Sun Oct 31 22:11:43 UTC 2021 Description="'HifiBerry Dac 2 HD - Failed to open alsa device'" # cat /proc/version --------------- Linux version 5.4.83-v7+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1379 SMP Mon Dec 14 13:08:57 GMT 2020 # cat /etc/os-release --------------- PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="c9a59086ecc33ef67efe5050b9e6041222366fda" VOLUMIO_FE_VERSION="00e2e4c742ba2276272c3bbf019e084877078dfe" VOLUMIO_FE3_VERSION="f97ca093505710744c259f0016c7a5c857decb5e" VOLUMIO_BE_VERSION="1ae4f31c145a39358ef738df59a1bad8e976bcd7" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumiobuster" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 29 Oct 2021 03:40:35 PM CEST" VOLUMIO_VERSION="3.129" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="302d5dfd9833ce33b1399bc53bb12afe" # ifconfig --------------- eth0: flags=4163 mtu 1500 inet 192.168.178.123 netmask 255.255.255.0 broadcast 192.168.178.255 ether b8:27:eb:b5:50:f3 txqueuelen 1000 (Ethernet) RX packets 162036 bytes 167829801 (160.0 MiB) RX errors 1 dropped 17 overruns 0 frame 1 TX packets 174418 bytes 177031426 (168.8 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73 mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 loop txqueuelen 1000 (Local Loopback) RX packets 1647 bytes 266303 (260.0 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 1647 bytes 266303 (260.0 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163 mtu 1500 inet 192.168.178.112 netmask 255.255.255.0 broadcast 192.168.178.255 ether b8:27:eb:e0:05:a6 txqueuelen 1000 (Ethernet) RX packets 271 bytes 45023 (43.9 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 62 bytes 18901 (18.4 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 # sudo iwconfig --------------- eth0 no wireless extensions. lo no wireless extensions. wlan0 IEEE 802.11 ESSID:"Wifi31358" Mode:Managed Frequency:5.62 GHz Access Point: 7C:FF:4D:02:8D:8A Bit Rate=12 Mb/s Tx-Power=31 dBm Retry short limit:7 RTS thr:off Fragment thr:off Encryption key:off Power Management:off Link Quality=33/70 Signal level=-77 dBm Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0 Tx excessive retries:0 Invalid misc:0 Missed beacon:0 # aplay -l --------------- xcb_connection_has_error() returned true **** List of PLAYBACK Hardware Devices **** card 0: b1 [bcm2835 HDMI 1], device 0: bcm2835 HDMI 1 [bcm2835 HDMI 1] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 1: Headphones [bcm2835 Headphones], device 0: bcm2835 Headphones [bcm2835 Headphones] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 2: sndrpihifiberry [snd_rpi_hifiberry_dacplushd], device 0: HiFiBerry DAC+ HD HiFi pcm179x-hifi-0 [HiFiBerry DAC+ HD HiFi pcm179x-hifi-0] Subdevices: 1/1 Subdevice #0: subdevice #0 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 8 22:08 ? 00:00:14 /sbin/init root 2 0 0 22:08 ? 00:00:00 [kthreadd] root 3 2 0 22:08 ? 00:00:00 [rcu_gp] root 4 2 0 22:08 ? 00:00:00 [rcu_par_gp] root 5 2 0 22:08 ? 00:00:00 [kworker/0:0-cgroup_destroy] root 6 2 0 22:08 ? 00:00:00 [kworker/0:0H-mmc_complete] root 7 2 0 22:08 ? 00:00:00 [kworker/u8:0-events_unbound] root 8 2 0 22:08 ? 00:00:00 [mm_percpu_wq] root 9 2 6 22:08 ? 00:00:10 [ksoftirqd/0] root 10 2 0 22:08 ? 00:00:00 [rcu_sched] root 11 2 0 22:08 ? 00:00:00 [migration/0] root 12 2 0 22:08 ? 00:00:00 [cpuhp/0] root 13 2 0 22:08 ? 00:00:00 [cpuhp/1] root 14 2 0 22:08 ? 00:00:00 [migration/1] root 15 2 0 22:08 ? 00:00:00 [ksoftirqd/1] root 16 2 0 22:08 ? 00:00:00 [kworker/1:0-events_power_efficient] root 17 2 0 22:08 ? 00:00:00 [kworker/1:0H-kblockd] root 18 2 0 22:08 ? 00:00:00 [cpuhp/2] root 19 2 0 22:08 ? 00:00:00 [migration/2] root 20 2 0 22:08 ? 00:00:00 [ksoftirqd/2] root 21 2 0 22:08 ? 00:00:00 [kworker/2:0-events] root 22 2 0 22:08 ? 00:00:00 [kworker/2:0H-kblockd] root 23 2 0 22:08 ? 00:00:00 [cpuhp/3] root 24 2 0 22:08 ? 00:00:00 [migration/3] root 25 2 0 22:08 ? 00:00:00 [ksoftirqd/3] root 26 2 0 22:08 ? 00:00:00 [kworker/3:0-mm_percpu_wq] root 27 2 0 22:08 ? 00:00:00 [kworker/3:0H-kblockd] root 28 2 0 22:08 ? 00:00:00 [kdevtmpfs] root 29 2 0 22:08 ? 00:00:00 [netns] root 30 2 0 22:08 ? 00:00:00 [kworker/0:1-events] root 31 2 0 22:08 ? 00:00:01 [kworker/1:1-events_power_efficient] root 32 2 0 22:08 ? 00:00:00 [kauditd] root 33 2 0 22:08 ? 00:00:00 [khungtaskd] root 34 2 0 22:08 ? 00:00:00 [oom_reaper] root 35 2 0 22:08 ? 00:00:00 [writeback] root 36 2 0 22:08 ? 00:00:00 [kcompactd0] root 54 2 0 22:08 ? 00:00:00 [kblockd] root 55 2 0 22:08 ? 00:00:00 [blkcg_punt_bio] root 56 2 0 22:08 ? 00:00:00 [watchdogd] root 57 2 0 22:08 ? 00:00:00 [kworker/3:1-events] root 58 2 0 22:08 ? 00:00:00 [rpciod] root 59 2 0 22:08 ? 00:00:00 [kworker/u9:0] root 60 2 0 22:08 ? 00:00:00 [xprtiod] root 61 2 0 22:09 ? 00:00:00 [kswapd0] root 62 2 0 22:09 ? 00:00:00 [nfsiod] root 63 2 0 22:09 ? 00:00:00 [kworker/2:1-events] root 64 2 0 22:09 ? 00:00:00 [iscsi_eh] root 65 2 0 22:09 ? 00:00:00 [dwc_otg] root 66 2 0 22:09 ? 00:00:00 [DWC Notificatio] root 67 2 0 22:09 ? 00:00:01 [kworker/1:2-events] root 68 2 0 22:09 ? 00:00:00 [vchiq-slot/0] root 69 2 0 22:09 ? 00:00:00 [vchiq-recy/0] root 70 2 0 22:09 ? 00:00:00 [vchiq-sync/0] root 71 2 0 22:09 ? 00:00:00 [vchiq-keep/0] root 72 2 0 22:09 ? 00:00:00 [SMIO] root 73 2 0 22:09 ? 00:00:00 [kworker/1:3-rcu_gp] root 74 2 0 22:09 ? 00:00:00 [kworker/1:4] root 82 2 0 22:09 ? 00:00:00 [mmc_complete] root 84 2 0 22:09 ? 00:00:00 [kworker/1:1H-kblockd] root 87 2 0 22:09 ? 00:00:00 [kworker/0:1H-mmc_complete] root 102 2 0 22:09 ? 00:00:00 [kworker/3:2-cgroup_destroy] root 107 2 0 22:09 ? 00:00:00 [kworker/0:2H-kblockd] root 111 2 0 22:09 ? 00:00:00 [kworker/3:1H-kblockd] root 112 2 0 22:09 ? 00:00:00 [kworker/3:2H-kblockd] root 113 2 0 22:09 ? 00:00:00 [jbd2/mmcblk0p2-] root 114 2 0 22:09 ? 00:00:00 [ext4-rsv-conver] root 115 2 0 22:09 ? 00:00:00 [kworker/2:1H-kblockd] root 117 2 0 22:09 ? 00:00:00 [kworker/u8:1-brcmf_wq/mmc1:0001:1] root 119 2 0 22:09 ? 00:00:00 [irq/166-usb-001] root 125 2 1 22:09 ? 00:00:01 [loop0] root 151 2 0 22:09 ? 00:00:00 [kworker/2:2H-kblockd] root 152 2 0 22:09 ? 00:00:00 [jbd2/mmcblk0p3-] root 153 2 0 22:09 ? 00:00:00 [ext4-rsv-conver] root 160 2 0 22:09 ? 00:00:00 [ipv6_addrconf] root 161 2 0 22:09 ? 00:00:00 [kworker/0:2-events] root 178 1 1 22:09 ? 00:00:01 /lib/systemd/systemd-journald root 192 2 0 22:09 ? 00:00:00 [kworker/2:2-events] root 202 2 0 22:09 ? 00:00:00 [kworker/u8:2-events_unbound] root 214 1 0 22:09 ? 00:00:01 /lib/systemd/systemd-udevd root 235 2 0 22:09 ? 00:00:00 [SMIO] root 249 2 0 22:09 ? 00:00:00 [kworker/1:2H-kblockd] root 258 2 0 22:09 ? 00:00:00 [mmal-vchiq] root 259 2 0 22:09 ? 00:00:00 [mmal-vchiq] root 260 2 0 22:09 ? 00:00:00 [mmal-vchiq] root 261 2 0 22:09 ? 00:00:00 [mmal-vchiq] root 302 2 0 22:09 ? 00:00:00 [cfg80211] root 335 2 0 22:09 ? 00:00:00 [kworker/3:3] root 336 2 0 22:09 ? 00:00:00 [brcmf_wq/mmc1:0] root 337 2 0 22:09 ? 00:00:00 [kworker/3:4-events] root 338 2 0 22:09 ? 00:00:00 [brcmf_wdog/mmc1] root 404 1 1 22:09 ? 00:00:02 /usr/sbin/haveged --Foreground --verbose=1 -w 1024 _rpc 411 1 0 22:09 ? 00:00:00 /sbin/rpcbind -f -w volumio 438 1 0 22:09 ? 00:00:00 /usr/local/bin/volumio-remote-updater root 441 1 0 22:09 ? 00:00:00 /usr/sbin/alsactl -E HOME=/run/alsa -s -n 19 -c rdaemon nobody 446 1 0 22:09 ? 00:00:00 /usr/sbin/thd --triggers /etc/triggerhappy/triggers.d/ --socket /run/thd.socket --user nobody --deviceglob /dev/input/event* message+ 460 1 1 22:09 ? 00:00:01 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only root 467 1 0 22:09 ? 00:00:00 /lib/systemd/systemd-logind avahi 468 1 0 22:09 ? 00:00:00 avahi-daemon: running [volumio-hbdac2hd-beta3.local] root 469 1 0 22:09 ? 00:00:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant root 484 2 0 22:09 ? 00:00:00 [kworker/0:3-events] root 487 2 0 22:09 ? 00:00:00 [kworker/0:4-events] avahi 523 468 0 22:09 ? 00:00:00 avahi-daemon: chroot helper root 604 1 0 22:09 ? 00:00:01 /usr/sbin/nmbd --foreground --no-process-group ntp 605 1 0 22:09 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 root 624 1 0 22:09 ? 00:00:00 /usr/sbin/ifplugd -i eth0 -q -f -u0 -d10 -w -I root 633 1 0 22:09 tty1 00:00:00 /sbin/agetty -o -p -- \u --noclear tty1 linux root 637 1 0 22:09 ? 00:00:00 /sbin/agetty -o -p -- \u --keep-baud 115200,38400,9600 ttyAMA0 vt220 root 643 1 0 22:09 ? 00:00:00 /usr/sbin/sshd -D root 658 604 0 22:09 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 667 2 0 22:09 ? 00:00:00 [kworker/u8:3] root 668 2 0 22:09 ? 00:00:00 [kworker/2:3-events] root 669 2 0 22:09 ? 00:00:00 [kworker/2:4-mm_percpu_wq] root 670 2 0 22:09 ? 00:00:00 [kworker/2:5-events] root 719 1 0 22:09 ? 00:00:00 /sbin/dhcpcd eth0 root 740 2 0 22:09 ? 00:00:00 [kworker/2:6-cgroup_destroy] root 741 2 0 22:09 ? 00:00:00 [kworker/2:7] root 757 1 0 22:09 ? 00:00:00 /usr/sbin/winbindd --foreground --no-process-group root 782 1 0 22:09 ? 00:00:00 wpa_supplicant -s -B -Dnl80211,wext -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 root 785 757 0 22:09 ? 00:00:00 winbindd: domain child [VOLUMIO-HBDAC2HD-BETA3] root 786 1 0 22:09 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 810 786 0 22:09 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 811 786 0 22:09 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 812 757 0 22:09 ? 00:00:00 winbindd: idmap child root 813 757 0 22:09 ? 00:00:00 winbindd: domain child [BUILTIN] root 814 786 0 22:09 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 837 1 0 22:09 ? 00:00:00 /sbin/dhcpcd volumio 917 1 59 22:09 ? 00:01:12 /usr/bin/node /volumio/index.js root 968 2 0 22:09 ? 00:00:00 [cifsiod] root 969 2 0 22:09 ? 00:00:00 [smb3decryptd] root 970 2 0 22:09 ? 00:00:00 [cifsfileinfoput] root 971 2 0 22:09 ? 00:00:00 [cifsoplockd] root 974 2 3 22:09 ? 00:00:04 [cifsd] volumio 996 917 0 22:09 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1011 996 3 22:09 ? 00:00:03 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1013 996 3 22:09 ? 00:00:03 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1015 996 3 22:09 ? 00:00:03 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 1116 1 0 22:10 ? 00:00:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf volumio 1154 1 0 22:10 ? 00:00:00 /bin/streaming-daemon volumio 1183 1 0 22:10 ? 00:00:00 /bin/sh /tmp/sshtunnel.sh volumio 1184 1183 0 22: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 d4nI4wt1NsYcchExrC0uZmuF3FH3-024e194918b720e737221d5c588e9994.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org volumio 1187 1184 0 22:10 ? 00:00:00 /usr/bin/ssh -o ServerAliveInterval 30 -o ServerAliveCountMax 3 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -N -p 2222 -R d4nI4wt1NsYcchExrC0uZmuF3FH3-024e194918b720e737221d5c588e9994.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org mpd 1233 1 4 22:10 ? 00:00:03 /usr/bin/mpd --no-daemon shairpo+ 1252 1 0 22:10 ? 00:00:00 /usr/bin/shairport-sync --configfile=/tmp/shairport-sync.conf volumio 1258 1 0 22:10 ? 00:00:00 /bin/sh /bin/bt/btstart.sh start volumio 1272 1 0 22:10 ? 00:00:00 /usr/bin/pulseaudio rtkit 1273 1 0 22:10 ? 00:00:00 /usr/lib/rtkit/rtkit-daemon root 1276 1 0 22:10 ? 00:00:00 /usr/lib/policykit-1/polkitd --no-debug volumio 1283 1 0 22:10 ? 00:00:00 /bin/sh -c /usr/bin/vtcs volumio 1284 1283 1 22:10 ? 00:00:01 /usr/bin/vtcs root 1287 1 0 22:10 ? 00:00:00 /usr/lib/bluetooth/bluetoothd --noplugin=sap volumio 1293 1258 1 22:10 ? 00:00:01 /usr/bin/python /bin/bt/simple-agent -c NoInputNoOutput volumio 1353 917 2 22:11 ? 00:00:00 /bin/sh -c /usr/bin/node /volumio/logsubmit.js 'HifiBerry Dac 2 HD - Failed to open alsa device' volumio 1354 1353 73 22:11 ? 00:00:00 /usr/bin/node /volumio/logsubmit.js HifiBerry Dac 2 HD - Failed to open alsa device volumio 1374 1354 0 22:11 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 1375 1374 0 22:11 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.5G 1.1G 1.3G 46% /imgpart /dev/loop0 473M 473M 0 100% /static overlay 12G 98M 12G 1% / devtmpfs 441M 0 441M 0% /dev tmpfs 485M 0 485M 0% /dev/shm tmpfs 485M 9.0M 476M 2% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 485M 0 485M 0% /sys/fs/cgroup tmpfs 485M 0 485M 0% /var/spool/cups tmpfs 20M 28K 20M 1% /var/log tmpfs 485M 68K 485M 1% /tmp tmpfs 485M 0 485M 0% /var/spool/cups/tmp /dev/mmcblk0p1 92M 61M 31M 67% /boot //192.168.178.11/music 3.5T 2.2T 1.4T 63% /mnt/NAS/Musik # mount --------------- /dev/mmcblk0p2 on /imgpart type ext4 (rw,relatime) /dev/loop0 on /static type squashfs (ro,relatime) overlay on / type overlay (rw,relatime,lowerdir=/mnt/static,upperdir=/mnt/ext/dyn,workdir=/mnt/ext/work) sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime) proc on /proc type proc (rw,relatime) devtmpfs on /dev type devtmpfs (rw,nosuid,size=451312k,nr_inodes=112828,mode=755) securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev,noexec) devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k) tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755) cgroup2 on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd) none on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700) cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct) cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio) cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids) cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset) cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=37,pgrp=1,timeout=0,minproto=5,maxproto=5,direct) debugfs on /sys/kernel/debug type debugfs (rw,relatime) mqueue on /dev/mqueue type mqueue (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime) 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 /tmp type tmpfs (rw,noatime,mode=755) 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,user) //192.168.178.11/music on /mnt/NAS/Musik type cifs (ro,relatime,vers=3.1.1,cache=strict,username=Musik,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.178.11,file_mode=0666,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=4194304,wsize=4194304,bsize=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:5000 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:4713 0.0.0.0:* LISTEN 1272/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:22 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:49149 0.0.0.0:* LISTEN 1116/upmpdcli tcp 0 0 0.0.0.0:445 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:49152 0.0.0.0:* LISTEN 1116/upmpdcli tcp 0 0 127.0.0.1:45196 127.0.0.1:3000 ESTABLISHED 438/volumio-remote- tcp 0 0 192.168.178.123:47310 195.48.36.151:80 TIME_WAIT - tcp 0 0 192.168.178.123:36560 172.67.141.32:443 ESTABLISHED 1154/streaming-daem tcp 0 0 192.168.178.123:56220 188.166.162.121:2222 ESTABLISHED 1187/ssh tcp 0 0 192.168.178.123:45082 192.168.178.24:3000 ESTABLISHED 917/node tcp 0 0 192.168.178.123:36586 172.67.141.32:443 ESTABLISHED 1154/streaming-daem tcp 0 0 192.168.178.123:36660 192.168.178.172:3000 ESTABLISHED 917/node tcp 0 0 192.168.178.123:51018 84.247.14.230:80 ESTABLISHED 917/node tcp 0 0 192.168.178.123:36542 172.67.141.32:443 ESTABLISHED 1154/streaming-daem tcp 0 0 127.0.0.1:38914 127.0.0.1:6599 ESTABLISHED 1116/upmpdcli tcp 0 0 192.168.178.123:36584 172.67.141.32:443 ESTABLISHED 1154/streaming-daem tcp 0 0 127.0.0.1:45238 127.0.0.1:3000 ESTABLISHED 917/node tcp 0 0 127.0.0.1:38902 127.0.0.1:6599 ESTABLISHED 1116/upmpdcli tcp 0 0 127.0.0.1:45202 127.0.0.1:3000 ESTABLISHED 917/node tcp 0 0 192.168.178.123:48992 35.201.97.85:443 ESTABLISHED 917/node tcp 0 0 192.168.178.123:48456 192.168.178.11:445 ESTABLISHED - tcp 0 0 192.168.178.123:44374 193.218.103.246:443 ESTABLISHED - tcp 0 0 127.0.0.1:45292 127.0.0.1:3000 ESTABLISHED 917/node tcp6 0 0 :::6599 :::* LISTEN 917/node tcp6 0 0 :::5000 :::* LISTEN - tcp6 0 0 :::6600 :::* LISTEN - tcp6 0 0 :::4713 :::* LISTEN 1272/pulseaudio tcp6 0 0 :::139 :::* LISTEN - tcp6 0 0 :::111 :::* LISTEN - tcp6 0 0 :::22 :::* LISTEN - tcp6 0 0 :::3000 :::* LISTEN 917/node tcp6 0 0 :::3001 :::* LISTEN 996/node tcp6 0 0 :::3005 :::* LISTEN 917/node tcp6 0 0 :::445 :::* LISTEN - tcp6 0 0 :::7777 :::* LISTEN 1154/streaming-daem tcp6 0 0 :::2019 :::* LISTEN 1284/vtcs tcp6 0 0 192.168.178.123:3000 192.168.178.30:45484 TIME_WAIT - tcp6 0 0 127.0.0.1:3000 127.0.0.1:45202 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45490 TIME_WAIT - tcp6 0 0 192.168.178.123:3000 192.168.178.30:45492 FIN_WAIT2 - tcp6 0 0 127.0.0.1:6599 127.0.0.1:38902 ESTABLISHED 917/node tcp6 0 0 127.0.0.1:6599 127.0.0.1:38914 ESTABLISHED 917/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:45238 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45480 TIME_WAIT - tcp6 0 0 192.168.178.123:3000 192.168.178.24:57164 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45486 TIME_WAIT - tcp6 0 0 192.168.178.123:3000 192.168.178.30:45498 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45496 FIN_WAIT2 - tcp6 0 0 127.0.0.1:3000 127.0.0.1:45196 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45478 TIME_WAIT - tcp6 0 0 192.168.178.123:3000 192.168.178.172:51738 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45474 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45494 FIN_WAIT2 - tcp6 0 0 127.0.0.1:3000 127.0.0.1:45292 ESTABLISHED 917/node tcp6 0 0 192.168.178.123:3000 192.168.178.30:45488 TIME_WAIT - tcp6 0 0 192.168.178.123:3000 192.168.178.30:45476 TIME_WAIT - # cat /etc/asound.conf --------------- pcm.!default { type empty slave.pcm "volumio" } pcm.volumio { type empty slave.pcm "volumioMultiRoomServer" } # This PCM switches output to the ALSA target named by the file /tmp/multiroom/server/switch.target pcm.volumioMultiRoomServer { type volumioswitch target_file "/tmp/multiroom/server/switch.target" control_fifo "/tmp/multiroom/server/switch.fifo" } # This PCM switches output to the ALSA target named by the file /tmp/multiroom/client/switch.target pcm.volumioMultiRoomClient { type volumioswitch target_file "/tmp/multiroom/client/switch.target" control_fifo "/tmp/multiroom/client/switch.fifo" } # This PCM performs any necessary rate/format/channel conversion before sending on to the Server FIFO pcm.volumioMultiRoom { type plug slave { pcm "volumioMultiRoomFIFO" rate 48000 format "S16_LE" channels 2 } rate_converter "speexrate_medium" } # Write to the FIFO watched by the Server pcm.volumioMultiRoomFIFO { type volumiofifo fifo "/tmp/multiroom/server/fifo" clear_on_drop false lead_in_frames 16384 } # This pcm is used by pcm.volumioMultiRoomServer and pcm.volumioMultiRoomClient to play audio on the local output pcm.volumioLocalPlayback { type empty slave.pcm "postMultiRoom" } # This pcm is used by pcm.volumioMultiRoomClient to discard audio and allow for faster switching pcm.volumioDiscard { type null } pcm.postMultiRoom { type empty slave.pcm "volumioOutput" } # There is always a plug before the hardware to be safe pcm.volumioOutput { type plug slave.pcm "volumioHw" } pcm.volumioHw { type hw card "MAX98357A" } # cat /var/log/mpd.log --------------- Oct 31 22:09 : zeroconf: No global port, disabling zeroconf Oct 31 22:09 : zeroconf: No global port, disabling zeroconf Oct 31 22:09 : client: [0] opened from local Oct 31 22:09 : exception: No such directory Oct 31 22:09 : client: [1] opened from local Oct 31 22:09 : zeroconf: No global port, disabling zeroconf Oct 31 22:09 : client: [0] opened from 127.0.0.1:44358 Oct 31 22:09 : client: [1] opened from 127.0.0.1:44366 Oct 31 22:09 : client: [2] opened from local Oct 31 22:09 : exception: Failed to read mixer for 'alsa': no such mixer control: PCM Oct 31 22:10 : zeroconf: No global port, disabling zeroconf Oct 31 22:10 : client: [0] opened from local ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:138:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 31 22:10 : exception: Failed to open "alsa" (alsa) Oct 31 22:10 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:10 : exception: Failed to open "alsa" (alsa) Oct 31 22:10 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:10 : player: problems opening audio device while playing "NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac" Oct 31 22:10 : exception: Failed to read mixer for 'alsa': no such mixer control: PCM Oct 31 22:11 : player: played "NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac" Oct 31 22:11 : exception: No such playlist ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:138:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 31 22:11 : exception: Failed to open "alsa" (alsa) Oct 31 22:11 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:11 : exception: Failed to open "alsa" (alsa) Oct 31 22:11 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:11 : player: problems opening audio device while playing "http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ" Oct 31 22:11 : player: played "http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ" Oct 31 22:11 : exception: No such playlist ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:138:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 31 22:11 : exception: Failed to open "alsa" (alsa) Oct 31 22:11 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:11 : exception: Failed to open "alsa" (alsa) Oct 31 22:11 : exception: nested: Failed to open ALSA device "volumio": No such device Oct 31 22:11 : player: problems opening audio device while playing "https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck" # cat /data/configuration/plugins.json --------------- { "music_service": { "airplay_emulation": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "inputs": { "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" } }, "streaming_services": { "status": { "type": "string", "value": "STARTING" } }, "cd_controller": { "status": { "type": "string", "value": "STARTED" } }, "smart_inputs": { "status": { "type": "string", "value": "STARTED" } }, "hi_res_audio": { "status": { "type": "string", "value": "STARTED" } }, "tidal": { "status": { "type": "string", "value": "STARTED" } }, "qobuz": { "status": { "type": "string", "value": "STARTED" } }, "tidalconnect": { "status": { "type": "string", "value": "STARTED" } } }, "audio_interface": { "outputs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "upnp": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "alsa_controller": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "bluetooth": { "status": { "type": "string", "value": "STARTED" } }, "multiroom": { "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" } }, "metavolumio": { "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" #save_absolute_paths_in_playlists "no" #metadata_to_use "artist,album,title,track,name,genre,date,composer,performer,disc" auto_update "no" #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 "volumio" 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 "2048" ############################################################################### # 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" ############################################################################### # volumio endpointstest --------------- TESTING REMOTE ENDPOINTS https://google.com, 868 ms: OK https://www.googleapis.com, 576 ms: OK https://securetoken.googleapis.com, 739 ms: OK https://myvolumio.firebaseio.com, 953 ms: OK https://functions.volumio.cloud, 1191 ms: OK https://oauth-performer.dfs.volumio.org, 718 ms: OK https://browsing-performer.dfs.volumio.org, 722 ms: OK http://cddb.volumio.org, 1186 ms: OK https://functions.volumio.cloud, 962 ms: OK http://pushupdates.volumio.org, 641 ms: OK http://plugins.volumio.org, 1246 ms: OK https://database.volumio.cloud, 1056 ms: OK https://radio-directory.firebaseapp.com, 519 ms: OK ---------- REMOTE ENDPOINTS TEST OK, all Endpoints are reachable ---------- # sudo journalctl -p 7 --------------- -- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Sun 2021-10-31 22:11:47 UTC. -- Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Booting Linux on physical CPU 0x0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Linux version 5.4.83-v7+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1379 SMP Mon Dec 14 13:08:57 GMT 2020 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: div instructions available: patching division code Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Memory policy: Data cache writealloc Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Reserved memory: created CMA memory pool at 0x3a000000, size 64 MiB Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: On node 0 totalpages: 253952 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Normal zone: 2232 pages used for memmap Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Normal zone: 0 pages reserved Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Normal zone: 253952 pages, LIFO batch:63 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: percpu: Embedded 20 pages/cpu s49740 r8192 d23988 u81920 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: pcpu-alloc: s49740 r8192 d23988 u81920 alloc=20*4096 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Built 1 zonelists, mobility grouping on. Total pages: 251720 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 loglevel=8 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Memory: 902628K/1015808K available (9216K kernel code, 698K rwdata, 2608K rodata, 1024K init, 827K bss, 47644K reserved, 65536K cma-reserved) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: ftrace: allocating 29205 entries in 58 pages Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: rcu: Hierarchical RCU implementation. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: random: get_random_bytes called from start_kernel+0x324/0x4f8 with crng_init=0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: arch_timer: cp15 timer(s) running at 19.20MHz (phys). Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Switching to timer-based delay loop, resolution 52ns Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Console: colour dummy device 80x30 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: printk: console [tty1] enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: pid_max: default: 32768 minimum: 301 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: LSM: Security Framework initializing Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Disabling memory control group subsystem Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: Testing write buffer coherency: ok Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Setting up static identity map for 0x100000 - 0x10003c Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: rcu: Hierarchical SRCU implementation. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: smp: Bringing up secondary CPUs ... Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: smp: Brought up 1 node, 4 CPUs Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: SMP: Total of 4 processors activated (153.60 BogoMIPS). Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: All CPU(s) started in HYP mode. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CPU: Virtualization extensions available. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: devtmpfs: initialized Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: pinctrl core: initialized pinctrl subsystem Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 16 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: audit: initializing netlink subsys (disabled) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Serial: AMBA PL011 UART driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2021-01-08 14:33, variant start Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: raspberrypi-firmware soc:firmware: Firmware hash is 194a85abd768c7334bbadc3f1911c10a7d18ed14 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: SCSI subsystem initialized Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver usbfs Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver hub Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new device driver usb Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: clocksource: Switched to clocksource arch_sys_counter Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: VFS: Disk quotas dquot_6.6.0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: FS-Cache: Loaded Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: CacheFiles: Loaded Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: thermal_sys: Registered thermal governor 'step_wise' Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 2 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: TCP: Hash tables configured (established 8192 bind 8192) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: RPC: Registered named UNIX socket transport module. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: RPC: Registered udp transport module. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: RPC: Registered tcp transport module. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Trying to unpack rootfs image as initramfs... Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Freeing initrd memory: 22504K Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Initialise system trusted keyrings Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: workingset: timestamp_bits=14 max_order=18 bucket_order=4 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: FS-Cache: Netfs 'nfs' registered for caching Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NFS: Registering the id_resolver key type Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type id_resolver registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type id_legacy registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type asymmetric registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Asymmetric key parser 'x509' registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: io scheduler mq-deadline registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: io scheduler kyber registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2708_fb soc:fb: FB found 1 display(s) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Console: switching to colour frame buffer device 80x30 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2835-rng 3f104000.rng: hwrng registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: vc-sm: Videocore shared memory driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: brd: module loaded Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: loop: module loaded Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Loading iSCSI transport class v2.0-870. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: libphy: Fixed MDIO Bus: probed Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver lan78xx Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver smsc95xx Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Core Release: 2.80a Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Setting default values for core params Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Finished setting default values for core params Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Using Buffer DMA mode Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Periodic Transfer Interrupt Enhancement - disabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Multiprocessor Interrupt Enhancement - disabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Dedicated Tx FIFOs mode Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = ba114000 dma = 0xfa114000 len=9024 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg: Microframe scheduler enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: WARN::hcd_init_fiq:458: FIQ ASM at 8070bf24 length 36 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: WARN::hcd_init_fiq:497: MPHI regs_base at be810000 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg 3f980000.usb: DWC OTG Controller Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg 3f980000.usb: irq 56, io mem 0x00000000 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Init: Port Power? op_state=1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Init: Power Port (0) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb usb1: Product: DWC OTG Controller Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb usb1: Manufacturer: Linux 5.4.83-v7+ dwc_otg_hcd Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb usb1: SerialNumber: 3f980000.usb Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-0:1.0: USB hub found Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-0:1.0: 1 port detected Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg: FIQ enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg: NAK holdoff enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg: FIQ split-transaction FSM enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Module dwc_common_port init Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver usb-storage Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mousedev: PS/2 mouse device common for all mice Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sdhci: Secure Digital Host Controller Interface driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sdhci: Copyright(c) Pierre Ossman Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sdhci-pltfm: SDHCI platform and OF driver helper Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: ledtrig-cpu: registered to indicate activity on CPUs Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hidraw: raw HID events driver (C) Jiri Kosina Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver usbhid Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usbhid: USB HID core driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: vchiq: vchiq_init_state: slot_zero = (ptrval) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: [vc_sm_connected_init]: start Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: [vc_sm_connected_init]: end - returning 0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Initializing XFRM netlink socket Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 17 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type dns_resolver registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Registering SWP/SWPB emulation handler Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: registered taskstats version 1 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Loading compiled-in X.509 certificates Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type ._fscrypt registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Key type .fscrypt registered Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: printk: console [ttyAMA0] enabled Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: 3f215040.serial: ttyS0 at MMIO 0x0 (irq = 53, base_baud = 50000000) is a 16550 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Indeed it is in host mode hprt0 = 00021501 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: sdhost: log_buf @ (ptrval) (fa113000) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: random: fast init done Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: of_cfs_init Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: of_cfs_init: OK Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Freeing unused kernel memory: 1024K Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Run /init as init process Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Indeed it is in host mode hprt0 = 00001101 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc0: host does not support reading read-only switch, assuming write-enable Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc0: new high speed SDHC card at address aaaa Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmcblk0: mmc0:aaaa SS16G 14.8 GiB Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmcblk0: p1 p2 p3 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: mmc1: new high speed SDIO card at address 0001 Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: Booting Volumio for BCM2835 Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: This script mounts rootfs RO with an overlay RW layer. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: IMGPART=/dev/mmcblk0p2 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: IMGFILE=/volumio_current.sqsh Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-1:1.0: USB hub found Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: Boot delay (except first time) will be 5 seconds Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-1:1.0: 4 ports detected Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: /dev/mmcblk0p2 not detected,retrying mdev in 5 seconds Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-1.1:1.0: USB hub found Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: hub 1-1.1:1.0: 3 ports detected Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: /dev/mmcblk0p2: Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: EXT4-fs (mmcblk0p2): recovery complete Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: Doing a 5 second delay here to give kernel load a headstart Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: dwc_otg_handle_wakeup_detected_intr lxstate = 2 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1.1: new high-speed USB device number 4 using dwc_otg Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800, bcdDevice= 3.00 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): No External EEPROM. Setting MAC Speed Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: libphy: lan78xx-mdiobus: probed Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): int urb period 64 Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: Checking for USB updates Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: EXT4-fs (mmcblk0p3): recovery complete Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: With Option: Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: VOLUMIO_VERSION="3.129" Feb 14 10:11:59 volumio-hbdac2hd-beta3 initramfs: Finish initramfs, continue booting Volumio Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: System time before build time, advancing clock. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 10 Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: Segment Routing with IPv6 Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Detected architecture arm. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Set hostname to . Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: uart-pl011 3f201000.serial: no DMA platform data Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: random: systemd: uninitialized urandom read (16 bytes read) Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Listening on Journal Socket. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Listening on Journal Socket (/dev/log). Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Listening on fsck to fsckd communication Socket. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Created slice User and Session Slice. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Listening on Journal Audit Socket. Feb 14 10:11:59 volumio-hbdac2hd-beta3 kernel: i2c /dev entries driver Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd-journald[178]: Journal started Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd-journald[178]: Runtime journal (/run/log/journal/510261faaece7a0c78916f67617bf954) is 3.7M, max 30.0M, 26.2M free. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd-modules-load[180]: Inserted module 'i2c_dev' Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Mounted Kernel Debug File System. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Started Remount Root and Kernel File Systems. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Mounted POSIX Message Queue File System. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Started Create list of required static device nodes for the current kernel. Feb 14 10:11:59 volumio-hbdac2hd-beta3 systemd[1]: Mounted Kernel Configuration File System. Oct 31 22:08:49 volumio-hbdac2hd-beta3 fake-hwclock[176]: Sun Oct 31 22:08:49 UTC 2021 Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Load/Save Random Seed... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Create System Users... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounted RPC Pipe File System. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Restore / save the current clock. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Apply Kernel Variables. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Load/Save Random Seed. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: dynamicswap.service: Succeeded. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Create System Users. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Create Static Device Nodes in /dev... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started udev Coldplug all Devices. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Create Static Device Nodes in /dev. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Reached target Local File Systems (Pre). Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounting /var/spool/cups... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounting /var/log... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounting /tmp... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting udev Kernel Device Manager... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Helper to synchronize boot up for ifupdown. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounted /var/spool/cups. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounted /var/log. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounted /tmp. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Flush Journal to Persistent Storage... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounting /var/spool/cups/tmp... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Mounted /var/spool/cups/tmp. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd-udevd[214]: Network interface NamePolicy= disabled on kernel command line, ignoring. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd-journald[178]: Runtime journal (/run/log/journal/510261faaece7a0c78916f67617bf954) is 7.5M, max 30.0M, 22.5M free. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started udev Kernel Device Manager. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Flush Journal to Persistent Storage. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Starting Show Plymouth Boot Screen... Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Received SIGRTMIN+20 from PID 228 (plymouthd). Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Show Plymouth Boot Screen. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Reached target Paths. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Reached target Local Encrypted Volumes. Oct 31 22:08:49 volumio-hbdac2hd-beta3 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Oct 31 22:08:49 volumio-hbdac2hd-beta3 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:49 volumio-hbdac2hd-beta3 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Oct 31 22:08:49 volumio-hbdac2hd-beta3 kernel: [vc_sm_connected_init]: start Oct 31 22:08:49 volumio-hbdac2hd-beta3 kernel: mc: Linux media interface: v0.10 Oct 31 22:08:49 volumio-hbdac2hd-beta3 kernel: [vc_sm_connected_init]: installed successfully Oct 31 22:08:50 volumio-hbdac2hd-beta3 systemd[1]: Found device /dev/ttyAMA0. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: videodev: Linux video capture interface: v2.00 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Oct 31 22:08:50 volumio-hbdac2hd-beta3 kernel: snd-rpi-hifiberry-dacplushd soc:sound: ASoC: failed to init link HiFiBerry DAC+ HD: -517 Oct 31 22:08:50 volumio-hbdac2hd-beta3 systemd-udevd[220]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 31 22:08:50 volumio-hbdac2hd-beta3 systemd-udevd[222]: Using default interface naming scheme 'v240'. Oct 31 22:08:51 volumio-hbdac2hd-beta3 systemd-udevd[222]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Oct 31 22:08:51 volumio-hbdac2hd-beta3 systemd[1]: Found device /dev/mmcblk0p1. Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: pcm179x 1-004c: No cache used with register defaults set! Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: usbcore: registered new interface driver brcmfmac Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: pcm512x 1-004d: Failed to reset device: -121 Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: pcm512x: probe of 1-004d failed with error -121 Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: snd-rpi-hifiberry-dacplushd soc:sound: pcm179x-hifi <-> 3f203000.i2s mapping ok Oct 31 22:08:51 volumio-hbdac2hd-beta3 kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,3-model-b-plus.txt failed with error -2 Oct 31 22:08:52 volumio-hbdac2hd-beta3 kernel: random: crng init done Oct 31 22:08:52 volumio-hbdac2hd-beta3 kernel: random: 7 urandom warning(s) missed due to ratelimiting Oct 31 22:08:52 volumio-hbdac2hd-beta3 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Oct 31 22:08:52 volumio-hbdac2hd-beta3 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd-udevd[227]: Using default interface naming scheme 'v240'. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd-udevd[227]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Oct 31 22:08:52 volumio-hbdac2hd-beta3 kernel: Under-voltage detected! (0x00050005) Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in FUSE Control File System being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting File System Check on /dev/mmcblk0p1... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Found device 7800. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started File System Check Daemon to report status. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting Load/Save RF Kill Switch Status... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd-udevd[217]: Process '/usr/sbin/alsactl -E HOME=/run/alsa restore 2' failed with exit code 99. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started Load/Save RF Kill Switch Status. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd-fsck[358]: fsck.fat 4.1 (2017-01-24) Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd-fsck[358]: /dev/mmcblk0p1: 254 files, 31124/46774 clusters Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started File System Check on /dev/mmcblk0p1. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Mounting /boot... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Mounted /boot. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Reached target Local File Systems. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting Raise network interfaces... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting Create Volatile Files and Directories... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started ifup for eth0. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Starting Preprocess NFS configuration... Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started ifup for wlan0. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: plymouth-read-write.service: Succeeded. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Received SIGRTMIN+20 from PID 228 (plymouthd). Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: nfs-config.service: Succeeded. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started Preprocess NFS configuration. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Reached target NFS client services. Oct 31 22:08:52 volumio-hbdac2hd-beta3 systemd[1]: Started Create Volatile Files and Directories. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting RPC bind portmap service... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Update UTMP about System Boot/Shutdown. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Reached target System Initialization. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Listening on triggerhappy.socket. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Daily apt download activities. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Daily apt upgrade and clean activities. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Listening on mpd.socket. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Listening on D-Bus System Message Bus Socket. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Reached target Sockets. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Reached target Basic System. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started volumio-remote-updater.service. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Wireless Services... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Iptables Module. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Manage Sound Card State (restore and store). Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting triggerhappy global hotkey daemon... Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[441]: alsactl 1.1.8 daemon started Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started UPnP Renderer front-end to MPD. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Volumio SSH enabler... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Save/Restore Sound Card State... Oct 31 22:08:53 volumio-hbdac2hd-beta3 volumiossh[451]: SSH file found, enabling SSH Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting dhcpcd on all interfaces... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started D-Bus System Message Bus. Oct 31 22:08:53 volumio-hbdac2hd-beta3 kernel: 8021q: 802.1Q VLAN Support v1.8 Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[441]: No state is present for card sndrpihifiberry Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[441]: Found hardware: "HifiberryDacplu" "" "" "" "" Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[441]: Hardware is initialized using a generic method Oct 31 22:08:53 volumio-hbdac2hd-beta3 thd[446]: Unable to parse trigger line: Oct 31 22:08:53 volumio-hbdac2hd-beta3 thd[446]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Oct 31 22:08:53 volumio-hbdac2hd-beta3 thd[446]: Unable to parse trigger line: Oct 31 22:08:53 volumio-hbdac2hd-beta3 thd[446]: Unable to parse trigger line: Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[441]: No state is present for card sndrpihifiberry Oct 31 22:08:53 volumio-hbdac2hd-beta3 dhcpcd[456]: Not running dhcpcd because /etc/network/interfaces Oct 31 22:08:53 volumio-hbdac2hd-beta3 dhcpcd[456]: defines some interfaces that will use a Oct 31 22:08:53 volumio-hbdac2hd-beta3 dhcpcd[456]: DHCP client or static address Oct 31 22:08:53 volumio-hbdac2hd-beta3 thd[446]: Found socket passed from systemd Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[455]: No state is present for card sndrpihifiberry Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Login Service... Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[455]: Found hardware: "HifiberryDacplu" "" "" "" "" Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[455]: Hardware is initialized using a generic method Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Starting WPA supplicant... Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Daily Cleanup of Temporary Directories. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Reached target Timers. Oct 31 22:08:53 volumio-hbdac2hd-beta3 alsactl[455]: No state is present for card sndrpihifiberry Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started triggerhappy global hotkey daemon. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Started Save/Restore Sound Card State. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Failed to start dhcpcd on all interfaces. Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd[1]: Reached target Sound Card. Oct 31 22:08:53 volumio-hbdac2hd-beta3 volumiossh[472]: Synchronizing state of ssh.service with SysV service script with /lib/systemd/systemd-sysv-install. Oct 31 22:08:53 volumio-hbdac2hd-beta3 volumiossh[472]: Executing: /lib/systemd/systemd-sysv-install enable ssh Oct 31 22:08:53 volumio-hbdac2hd-beta3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 31 22:08:53 volumio-hbdac2hd-beta3 systemd-logind[467]: New seat seat0. Oct 31 22:08:53 volumio-hbdac2hd-beta3 sh[370]: eth0: waiting for carrier Oct 31 22:08:53 volumio-hbdac2hd-beta3 kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 31 22:08:53 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: waiting for carrier Oct 31 22:08:53 volumio-hbdac2hd-beta3 sh[370]: eth0: carrier acquired Oct 31 22:08:53 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: carrier acquired Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started Login Service. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started RPC bind portmap service. Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[370]: DUID 00:01:00:01:29:0e:b8:09:b8:27:eb:b5:50:f3 Oct 31 22:08:54 volumio-hbdac2hd-beta3 dhcpcd[416]: DUID 00:01:00:01:29:0e:b8:09:b8:27:eb:b5:50:f3 Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[370]: eth0: IAID eb:b5:50:f3 Oct 31 22:08:54 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: IAID eb:b5:50:f3 Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[370]: eth0: adding address fe80::7dd8:37ea:bf7d:a14d Oct 31 22:08:54 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: adding address fe80::7dd8:37ea:bf7d:a14d Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[370]: ipv6_addaddr1: Permission denied Oct 31 22:08:54 volumio-hbdac2hd-beta3 dhcpcd[416]: ipv6_addaddr1: Permission denied Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Successfully dropped root privileges. Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: avahi-daemon 0.7 starting up. Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Successfully called chroot(). Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Successfully dropped remaining capabilities. Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Loading service file /services/volumio.service. Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[375]: wlan0=wlan0 Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Network interface enumeration completed. Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Server startup complete. Host name is volumio-hbdac2hd-beta3.local. Local service cookie is 2121373670. Oct 31 22:08:54 volumio-hbdac2hd-beta3 avahi-daemon[468]: Service "Volumio-HBDac2HD-Beta3" (/services/volumio.service) successfully established. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Reached target RPC Port Mapper. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Reached target Remote File Systems (Pre). Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Reached target Remote File Systems. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started Raise network interfaces. Oct 31 22:08:54 volumio-hbdac2hd-beta3 sh[370]: eth0: soliciting an IPv6 router Oct 31 22:08:54 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: soliciting an IPv6 router Oct 31 22:08:54 volumio-hbdac2hd-beta3 loadcpufreq[532]: Loading cpufreq kernel modules...done (none). Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Started WPA supplicant. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Reached target Network. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Starting Permit User Sessions... Oct 31 22:08:54 volumio-hbdac2hd-beta3 wpa_supplicant[469]: Successfully initialized wpa_supplicant Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Starting Network Time Service... Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Starting Music Player Daemon... Oct 31 22:08:54 volumio-hbdac2hd-beta3 systemd[1]: Reached target Network is Online. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting Samba NMB Daemon... Oct 31 22:08:55 volumio-hbdac2hd-beta3 sh[370]: eth0: rebinding lease of 192.168.178.123 Oct 31 22:08:55 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: rebinding lease of 192.168.178.123 Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 31 22:08:55 volumio-hbdac2hd-beta3 sh[370]: eth0: probing address 192.168.178.123/24 Oct 31 22:08:55 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: probing address 192.168.178.123/24 Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting LSB: Brings up/down network automatically... Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting /etc/rc.local Compatibility... Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting OpenBSD Secure Shell server... Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Permit User Sessions. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started /etc/rc.local Compatibility. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: iptables.service: Succeeded. Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[588]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[588]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Network Time Service. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting Terminate Plymouth Boot Screen... Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Starting Hold until boot process finishes up... Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: proto: precision = 1.458 usec (-19) Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: ifplugd 0.28 initializing. Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: Using interface eth0/B8:27:EB:B5:50:F3 with driver (version: ) Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Received SIGRTMIN+21 from PID 228 (plymouthd). Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: Using detection mode: SIOCETHTOOL Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: Initialization complete, link beat detected. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Received SIGRTMIN+21 from PID 228 (plymouthd). Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: plymouth-quit-wait.service: Succeeded. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Hold until boot process finishes up. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: plymouth-start.service: Succeeded. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: plymouth-quit.service: Succeeded. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Terminate Plymouth Boot Screen. Oct 31 22:08:55 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: Error: No active session Oct 31 22:08:55 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:08:55] [info] asio async_connect error: system:111 (Connection refused) Oct 31 22:08:55 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:08:55] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 31 22:08:55 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:08:55] [error] handle_connect error: Underlying Transport Error Oct 31 22:08:55 volumio-hbdac2hd-beta3 cpufrequtils[582]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: Listen and drop on 0 v6wildcard [::]:123 Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: Listen normally on 2 lo 127.0.0.1:123 Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: Listening on routing socket on fd #19 for interface updates Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 31 22:08:55 volumio-hbdac2hd-beta3 ntpd[605]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Getty on tty1. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started Serial Getty on ttyAMA0. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Reached target Login Prompts. Oct 31 22:08:55 volumio-hbdac2hd-beta3 systemd[1]: Started LSB: set CPUFreq kernel parameters. Oct 31 22:08:55 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Oct 31 22:08:56 volumio-hbdac2hd-beta3 haveged[404]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Oct 31 22:08:56 volumio-hbdac2hd-beta3 haveged[404]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Oct 31 22:08:56 volumio-hbdac2hd-beta3 haveged[404]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00382 Oct 31 22:08:56 volumio-hbdac2hd-beta3 haveged[404]: haveged: fills: 0, generated: 0 Oct 31 22:08:56 volumio-hbdac2hd-beta3 sshd[643]: Server listening on 0.0.0.0 port 22. Oct 31 22:08:56 volumio-hbdac2hd-beta3 sshd[643]: Server listening on :: port 22. Oct 31 22:08:56 volumio-hbdac2hd-beta3 systemd[1]: Started OpenBSD Secure Shell server. Oct 31 22:08:56 volumio-hbdac2hd-beta3 volumio[447]: Could not open config: /tmp/upmpdcli.conf Oct 31 22:08:56 volumio-hbdac2hd-beta3 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 31 22:08:56 volumio-hbdac2hd-beta3 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 31 22:08:56 volumio-hbdac2hd-beta3 ntpd[605]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 31 22:08:56 volumio-hbdac2hd-beta3 systemd[1]: Reloading. Oct 31 22:08:57 volumio-hbdac2hd-beta3 systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 31 22:08:57 volumio-hbdac2hd-beta3 ntpd[605]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 31 22:08:57 volumio-hbdac2hd-beta3 systemd[1]: volumiossh.service: Current command vanished from the unit file, execution of the command list won't be resumed. Oct 31 22:08:57 volumio-hbdac2hd-beta3 systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Oct 31 22:08:57 volumio-hbdac2hd-beta3 systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: [2021/10/31 22:08:57.940301, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: started asyncdns process 658 Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: [2021/10/31 22:08:57.944579, 0] ../lib/util/become_daemon.c:149(daemon_status) Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: [2021/10/31 22:08:57.944872, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Oct 31 22:08:57 volumio-hbdac2hd-beta3 nmbd[604]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Oct 31 22:08:57 volumio-hbdac2hd-beta3 systemd[1]: serial-getty@ttyAMA0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Oct 31 22:08:58 volumio-hbdac2hd-beta3 systemd[1]: systemd-rfkill.service: Succeeded. Oct 31 22:08:58 volumio-hbdac2hd-beta3 ntpd[605]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 31 22:08:58 volumio-hbdac2hd-beta3 systemd[1]: Reloading. Oct 31 22:08:59 volumio-hbdac2hd-beta3 ntpd[605]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 31 22:08:59 volumio-hbdac2hd-beta3 systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 31 22:09:00 volumio-hbdac2hd-beta3 systemd[1]: Reloading. Oct 31 22:09:00 volumio-hbdac2hd-beta3 sh[370]: eth0: leased 192.168.178.123 for 864000 seconds Oct 31 22:09:00 volumio-hbdac2hd-beta3 sh[370]: eth0: adding route to 192.168.178.0/24 Oct 31 22:09:00 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: leased 192.168.178.123 for 864000 seconds Oct 31 22:09:00 volumio-hbdac2hd-beta3 sh[370]: eth0: adding default route via 192.168.178.1 Oct 31 22:09:00 volumio-hbdac2hd-beta3 avahi-daemon[468]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.123. Oct 31 22:09:00 volumio-hbdac2hd-beta3 avahi-daemon[468]: New relevant interface eth0.IPv4 for mDNS. Oct 31 22:09:00 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: adding route to 192.168.178.0/24 Oct 31 22:09:00 volumio-hbdac2hd-beta3 avahi-daemon[468]: Registering new address record for 192.168.178.123 on eth0.IPv4. Oct 31 22:09:00 volumio-hbdac2hd-beta3 dhcpcd[416]: eth0: adding default route via 192.168.178.1 Oct 31 22:09:00 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:00] [info] asio async_connect error: system:111 (Connection refused) Oct 31 22:09:00 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:00] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 31 22:09:00 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:00] [error] handle_connect error: Underlying Transport Error Oct 31 22:09:00 volumio-hbdac2hd-beta3 sh[370]: forked to background, child pid 719 Oct 31 22:09:00 volumio-hbdac2hd-beta3 dhcpcd[416]: forked to background, child pid 719 Oct 31 22:09:00 volumio-hbdac2hd-beta3 wireless.js[439]: WIRELESS DAEMON: start Oct 31 22:09:00 volumio-hbdac2hd-beta3 wireless.js[439]: WIRELESS: Loaded configuration Oct 31 22:09:00 volumio-hbdac2hd-beta3 wireless.js[439]: Cleaning previous... Oct 31 22:09:01 volumio-hbdac2hd-beta3 systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 31 22:09:01 volumio-hbdac2hd-beta3 mpd[638]: Oct 31 22:09 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 22:09:02 volumio-hbdac2hd-beta3 systemd[1]: volumiossh.service: Succeeded. Oct 31 22:09:02 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio SSH enabler. Oct 31 22:09:02 volumio-hbdac2hd-beta3 mpd[638]: Oct 31 22:09 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Oct 31 22:09:02 volumio-hbdac2hd-beta3 mpd[638]: Oct 31 22:09 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Oct 31 22:09:02 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: client: ifup: interface eth0 already configured Oct 31 22:09:02 volumio-hbdac2hd-beta3 sh[370]: eth0=eth0 Oct 31 22:09:02 volumio-hbdac2hd-beta3 systemd[1]: Started Music Player Daemon. Oct 31 22:09:02 volumio-hbdac2hd-beta3 ntpd[605]: Listen normally on 3 eth0 192.168.178.123:123 Oct 31 22:09:02 volumio-hbdac2hd-beta3 ntpd[605]: new interface(s) found: waking up resolver Oct 31 22:09:02 volumio-hbdac2hd-beta3 ifplugd(eth0)[624]: Program executed successfully. Oct 31 22:09:02 volumio-hbdac2hd-beta3 ifplugd[596]: Network Interface Plugging Daemon...start eth0...done. Oct 31 22:09:02 volumio-hbdac2hd-beta3 systemd[1]: Started LSB: Brings up/down network automatically. Oct 31 22:09:02 volumio-hbdac2hd-beta3 sudo[746]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 31 22:09:02 volumio-hbdac2hd-beta3 sudo[746]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:02 volumio-hbdac2hd-beta3 sudo[746]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:02 volumio-hbdac2hd-beta3 sudo[754]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 31 22:09:02 volumio-hbdac2hd-beta3 sudo[754]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[754]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:03 volumio-hbdac2hd-beta3 nmbd[604]: [2021/10/31 22:09:03.239072, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 31 22:09:03 volumio-hbdac2hd-beta3 nmbd[604]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 31 22:09:03 volumio-hbdac2hd-beta3 systemd[1]: Started Samba NMB Daemon. Oct 31 22:09:03 volumio-hbdac2hd-beta3 systemd[1]: Starting Samba Winbind Daemon... Oct 31 22:09:03 volumio-hbdac2hd-beta3 wireless.js[439]: Stopped aP Oct 31 22:09:03 volumio-hbdac2hd-beta3 wireless.js[439]: Start wireless flow Oct 31 22:09:03 volumio-hbdac2hd-beta3 wireless.js[439]: Stopped hotspot (if there).. Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[763]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[763]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[763]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[765]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[765]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[765]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:03 volumio-hbdac2hd-beta3 wireless.js[439]: DHCP IP Oct 31 22:09:03 volumio-hbdac2hd-beta3 wireless.js[439]: Start ap Oct 31 22:09:03 volumio-hbdac2hd-beta3 wpa_supplicant[767]: Successfully initialized wpa_supplicant Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[768]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Oct 31 22:09:03 volumio-hbdac2hd-beta3 sudo[768]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:03 volumio-hbdac2hd-beta3 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 31 22:09:03 volumio-hbdac2hd-beta3 dhcpcd[769]: dev: loaded udev Oct 31 22:09:03 volumio-hbdac2hd-beta3 dhcpcd-run-hooks[778]: wlan0: starting wpa_supplicant Oct 31 22:09:03 volumio-hbdac2hd-beta3 winbindd[757]: [2021/10/31 22:09:03.887535, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 31 22:09:03 volumio-hbdac2hd-beta3 winbindd[757]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 31 22:09:03 volumio-hbdac2hd-beta3 winbindd[757]: [2021/10/31 22:09:03.937802, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 31 22:09:03 volumio-hbdac2hd-beta3 systemd[1]: Started Samba Winbind Daemon. Oct 31 22:09:03 volumio-hbdac2hd-beta3 winbindd[757]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 31 22:09:03 volumio-hbdac2hd-beta3 systemd[1]: Starting Samba SMB Daemon... Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd-run-hooks[787]: wlan0: failed to start wpa_supplicant Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd-run-hooks[788]: wlan0: Successfully initialized wpa_supplicant ctrl_iface exists and seems to be in use - cannot override it Delete '/var/run/wpa_supplicant/wlan0' manually if it is not used anymore Failed to initialize control interface '/var/run/wpa_supplicant'. You may have another wpa_supplicant process already running or the file was left by an unclean termination of wpa_supplicant in which case you will need to manually remove this file before starting wpa_supplicant again. nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: wlan0: connected to Access Point `' Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: DUID 00:01:00:01:29:0e:b8:09:b8:27:eb:b5:50:f3 Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: IAID eb:b5:50:f3 Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: adding address fe80::7dd8:37ea:bf7d:a14d Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: ipv6_addaddr1: Permission denied Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: wlan0: waiting for carrier Oct 31 22:09:04 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: soliciting an IPv6 router Oct 31 22:09:04 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:04 volumio-hbdac2hd-beta3 sudo[807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:04 volumio-hbdac2hd-beta3 sudo[807]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:04 volumio-hbdac2hd-beta3 sudo[807]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:05 volumio-hbdac2hd-beta3 smbd[786]: [2021/10/31 22:09:05.007894, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 31 22:09:05 volumio-hbdac2hd-beta3 smbd[786]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 31 22:09:05 volumio-hbdac2hd-beta3 systemd[1]: Started Samba SMB Daemon. Oct 31 22:09:05 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: rebinding lease of 192.168.178.123 Oct 31 22:09:05 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: leased 192.168.178.123 for 864000 seconds Oct 31 22:09:05 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: adding route to 192.168.178.0/24 Oct 31 22:09:05 volumio-hbdac2hd-beta3 dhcpcd[769]: eth0: adding default route via 192.168.178.1 Oct 31 22:09:05 volumio-hbdac2hd-beta3 dhcpcd[769]: forked to background, child pid 837 Oct 31 22:09:05 volumio-hbdac2hd-beta3 sudo[768]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:05 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:05 volumio-hbdac2hd-beta3 sudo[839]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:05 volumio-hbdac2hd-beta3 sudo[839]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:05 volumio-hbdac2hd-beta3 sudo[839]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:06 volumio-hbdac2hd-beta3 wpa_supplicant[782]: wlan0: Trying to associate with SSID 'Wifi31358' Oct 31 22:09:06 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:06 volumio-hbdac2hd-beta3 sudo[842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:06 volumio-hbdac2hd-beta3 sudo[842]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:06 volumio-hbdac2hd-beta3 sudo[842]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:07 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:07 volumio-hbdac2hd-beta3 sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:07 volumio-hbdac2hd-beta3 sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:07 volumio-hbdac2hd-beta3 sudo[845]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:08 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:08] [info] asio async_connect error: system:111 (Connection refused) Oct 31 22:09:08 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:08] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 31 22:09:08 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:08] [error] handle_connect error: Underlying Transport Error Oct 31 22:09:08 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:08 volumio-hbdac2hd-beta3 sudo[848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:08 volumio-hbdac2hd-beta3 sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:08 volumio-hbdac2hd-beta3 sudo[848]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:09 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:09 volumio-hbdac2hd-beta3 sudo[851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:09 volumio-hbdac2hd-beta3 sudo[851]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:09 volumio-hbdac2hd-beta3 sudo[851]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: carrier acquired Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: connected to Access Point `Wifi31358' Oct 31 22:09:09 volumio-hbdac2hd-beta3 wpa_supplicant[782]: wlan0: Associated with 7c:ff:4d:02:8d:8a Oct 31 22:09:09 volumio-hbdac2hd-beta3 wpa_supplicant[782]: wlan0: CTRL-EVENT-CONNECTED - Connection to 7c:ff:4d:02:8d:8a completed [id=0 id_str=] Oct 31 22:09:09 volumio-hbdac2hd-beta3 wpa_supplicant[782]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: IAID eb:e0:05:a6 Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: adding address fe80::66c1:d6a4:5172:2e43 Oct 31 22:09:09 volumio-hbdac2hd-beta3 wpa_supplicant[782]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CH Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: ipv6_addaddr1: Permission denied Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: carrier lost Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: carrier acquired Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: IAID eb:e0:05:a6 Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: rebinding lease of 192.168.178.112 Oct 31 22:09:09 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: probing address 192.168.178.112/24 Oct 31 22:09:10 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: soliciting an IPv6 router Oct 31 22:09:10 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:10 volumio-hbdac2hd-beta3 sudo[874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:10 volumio-hbdac2hd-beta3 sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:10 volumio-hbdac2hd-beta3 sudo[874]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:11 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:11 volumio-hbdac2hd-beta3 sudo[877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:11 volumio-hbdac2hd-beta3 sudo[877]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:11 volumio-hbdac2hd-beta3 sudo[877]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:12 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:12 volumio-hbdac2hd-beta3 sudo[880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:12 volumio-hbdac2hd-beta3 sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:12 volumio-hbdac2hd-beta3 sudo[880]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:13 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:13 volumio-hbdac2hd-beta3 sudo[883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:13 volumio-hbdac2hd-beta3 sudo[883]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:13 volumio-hbdac2hd-beta3 sudo[883]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:14 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:14 volumio-hbdac2hd-beta3 sudo[886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:14 volumio-hbdac2hd-beta3 sudo[886]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:14 volumio-hbdac2hd-beta3 sudo[886]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:14 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: leased 192.168.178.112 for 864000 seconds Oct 31 22:09:14 volumio-hbdac2hd-beta3 avahi-daemon[468]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.178.112. Oct 31 22:09:14 volumio-hbdac2hd-beta3 avahi-daemon[468]: New relevant interface wlan0.IPv4 for mDNS. Oct 31 22:09:14 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: adding route to 192.168.178.0/24 Oct 31 22:09:14 volumio-hbdac2hd-beta3 avahi-daemon[468]: Registering new address record for 192.168.178.112 on wlan0.IPv4. Oct 31 22:09:14 volumio-hbdac2hd-beta3 dhcpcd[837]: wlan0: adding default route via 192.168.178.1 Oct 31 22:09:15 volumio-hbdac2hd-beta3 wireless.js[439]: trying... Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[910]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[910]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:15 volumio-hbdac2hd-beta3 wireless.js[439]: Connected to: ----Wifi31358 Oct 31 22:09:15 volumio-hbdac2hd-beta3 wireless.js[439]: ---- Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[913]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[913]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:15 volumio-hbdac2hd-beta3 sudo[913]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:15 volumio-hbdac2hd-beta3 wireless.js[439]: ... joined AP, wlan0 IPv4 is 192.168.178.112, ipV6 is undefined Oct 31 22:09:15 volumio-hbdac2hd-beta3 wireless.js[439]: It's done! AP Oct 31 22:09:15 volumio-hbdac2hd-beta3 systemd[1]: Started Wireless Services. Oct 31 22:09:15 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Backend Module. Oct 31 22:09:15 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Streaming Daemon. Oct 31 22:09:16 volumio-hbdac2hd-beta3 volumio-streaming-daemon[918]: ############################ Oct 31 22:09:16 volumio-hbdac2hd-beta3 volumio-streaming-daemon[918]: # Volumio Streaming Daemon # Oct 31 22:09:16 volumio-hbdac2hd-beta3 volumio-streaming-daemon[918]: # Running on port 7777 # Oct 31 22:09:16 volumio-hbdac2hd-beta3 volumio-streaming-daemon[918]: ############################ Oct 31 22:09:16 volumio-hbdac2hd-beta3 volumio-streaming-daemon[918]: Environment: production Oct 31 22:09:16 volumio-hbdac2hd-beta3 ntpd[605]: Listen normally on 4 wlan0 192.168.178.112:123 Oct 31 22:09:16 volumio-hbdac2hd-beta3 ntpd[605]: new interface(s) found: waking up resolver Oct 31 22:09:18 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:18] [info] asio async_connect error: system:111 (Connection refused) Oct 31 22:09:18 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:18] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 31 22:09:18 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:18] [error] handle_connect error: Underlying Transport Error Oct 31 22:09:20 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:20 volumio-hbdac2hd-beta3 volumio[917]: info: ----- Volumio2 ---- Oct 31 22:09:20 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:20 volumio-hbdac2hd-beta3 volumio[917]: info: ----- System startup ---- Oct 31 22:09:20 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:22 volumio-hbdac2hd-beta3 systemd[1]: systemd-fsckd.service: Succeeded. Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO Environment detected Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Plugin folders cleanup Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning into folder /volumio/app/plugins/ Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category audio_interface Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category miscellanea Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category music_service Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category plugins.json Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category system_controller Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning category user_interface Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning into folder /data/plugins/ Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Plugin folders cleanup completed Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: ----- Core plugins startup ---- Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugins from folder /volumio/app/plugins/ Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin upnp to MyMusic Plugins Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugins from folder /data/plugins/ Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "system"... Oct 31 22:09:23 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "appearance"... Oct 31 22:09:23 volumio-hbdac2hd-beta3 btuart[436]: Initialization timed out. Oct 31 22:09:23 volumio-hbdac2hd-beta3 btuart[436]: bcm43xx_init Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: hciuart.service: Control process exited, code=exited, status=1/FAILURE Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: hciuart.service: Failed with result 'exit-code'. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Failed to start Configure Bluetooth Modems connected by UART. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Reached target Multi-User System. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Reached target Graphical Interface. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 31 22:09:23 volumio-hbdac2hd-beta3 systemd[1]: Startup finished in 15.325s (kernel) + 36.955s (userspace) = 52.280s. Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "network"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Refreshing Cached IP Addresses Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "services"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[942]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "alsa_controller"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[942]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:26 volumio-hbdac2hd-beta3 sudo[944]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: warn: Unable to locate the audio output device HiFiBerry DAC2 HD. Please configure a valid output device. Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "wizard"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "volumio_command_line_client"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "upnp"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718166852] Starting Upmpd Daemon Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "my_music"... Oct 31 22:09:26 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "mpd"... Oct 31 22:09:27 volumio-hbdac2hd-beta3 volumio[917]: info: Creating MPD Configuration file Oct 31 22:09:27 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "upnp_browser"... Oct 31 22:09:27 volumio-hbdac2hd-beta3 sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 22:09:27 volumio-hbdac2hd-beta3 sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:27 volumio-hbdac2hd-beta3 sudo[954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 22:09:27 volumio-hbdac2hd-beta3 sudo[952]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:27 volumio-hbdac2hd-beta3 sudo[954]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:27 volumio-hbdac2hd-beta3 systemd[1]: Stopping Music Player Daemon... Oct 31 22:09:28 volumio-hbdac2hd-beta3 systemd[1]: mpd.service: Succeeded. Oct 31 22:09:28 volumio-hbdac2hd-beta3 systemd[1]: Stopped Music Player Daemon. Oct 31 22:09:28 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:28] [connect] Successful connection Oct 31 22:09:28 volumio-hbdac2hd-beta3 systemd[1]: Starting Music Player Daemon... Oct 31 22:09:28 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "networkfs"... Oct 31 22:09:29 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Udev Watcher for removable devices Oct 31 22:09:29 volumio-hbdac2hd-beta3 sudo[962]: 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.178.11/music /mnt/NAS/Musik Oct 31 22:09:29 volumio-hbdac2hd-beta3 sudo[962]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:29 volumio-hbdac2hd-beta3 kernel: FS-Cache: Netfs 'cifs' registered for caching Oct 31 22:09:29 volumio-hbdac2hd-beta3 kernel: Key type cifs.spnego registered Oct 31 22:09:29 volumio-hbdac2hd-beta3 kernel: Key type cifs.idmap registered Oct 31 22:09:29 volumio-hbdac2hd-beta3 kernel: CIFS: Attempting to mount //192.168.178.11/music Oct 31 22:09:29 volumio-hbdac2hd-beta3 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. Oct 31 22:09:30 volumio-hbdac2hd-beta3 sudo[962]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring mount for partition: boot Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring mount for partition: volumio Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring mount for partition: volumio_data Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "alarm-clock"... Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "airplay_emulation"... Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Shairport Sync Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "last_100"... Oct 31 22:09:30 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "webradio"... Oct 31 22:09:30 volumio-hbdac2hd-beta3 mpd[959]: Oct 31 22:09 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "i2s_dacs"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "volumiodiscovery"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** For more information see Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: *** WARNING *** For more information see Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** For more information see Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 22:09:31 volumio-hbdac2hd-beta3 node[917]: *** WARNING *** For more information see Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: Started advertising with name: Volumio-HBDac2HD-Beta3 Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "outputs"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "albumart"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 mpd[959]: Oct 31 22:09 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Oct 31 22:09:31 volumio-hbdac2hd-beta3 mpd[959]: Oct 31 22:09 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Plugin example_plugin is not enabled Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "inputs"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 systemd[1]: Started Music Player Daemon. Oct 31 22:09:31 volumio-hbdac2hd-beta3 sudo[954]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "updater_comm"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Plugin mpdemulation is not enabled Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "rest_api"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading plugin "websocket"... Oct 31 22:09:31 volumio-hbdac2hd-beta3 volumio[917]: info: Loading i18n strings for locale de Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: Updating browse sources language Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::initPlayerControls Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: Express server listening on port 3000 Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: [Metrics] WebUI: 12s 907.55ms Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: Volumio Calling Home Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::resetVolumioState Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::getcurrentVolume Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: Forking 3 albumart workers Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: MPD Permissions set Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio-remote-updater[438]: [2021-10-31 22:09:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1635718168 101 Oct 31 22:09:32 volumio-hbdac2hd-beta3 volumio[917]: info: Volumio called home Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: MPD running with PID959 Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: ,establishing connection Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: Reloading queue from file Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: VolumeController:: Volume=46 Mute =false Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::updateTrackBlock Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrackBlock Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setRepeat null single undefined Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setRandom null Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:09:33 volumio-hbdac2hd-beta3 volumio[917]: info: Setting Device type: Raspberry PI Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- Client requests Volume 10 Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: VolumeController::SetAlsaVolume10 Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: Starting albumart workers Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: Starting albumart workers Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: Starting albumart workers Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: Completed loading Core Plugins Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: Preparing to generate the ALSA configuration file Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 31 22:09:34 volumio-hbdac2hd-beta3 volumio[917]: info: Setting volume on startup at 10 Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: adding 0dbafe8b-169d-4479-bc11-05bbbce07874 Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio-HBDac2HD-Beta3 Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:35 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: VolumeController:: Volume=46 Mute =false Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: this is already registered, 0dbafe8b-169d-4479-bc11-05bbbce07874 Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio-HBDac2HD-Beta3 Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:36 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1081]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:37 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: adding f7e8c432-202b-4163-9c31-ee97b3701219 Oct 31 22:09:37 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio-boss-01 Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1081]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:37 volumio-hbdac2hd-beta3 sudo[1083]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: Asound.conf file written Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1087]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1087]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: No state is present for card sndrpihifiberry Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: Found hardware: "HifiberryDacplu" "" "" "" "" Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: Hardware is initialized using a generic method Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: No state is present for card sndrpihifiberry Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: Output device has changed, restarting MPD Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: Output device has changed, restarting Shairport Sync Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1092]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 22:09:39 volumio-hbdac2hd-beta3 sudo[1094]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:39 volumio-hbdac2hd-beta3 systemd[1]: Stopping Music Player Daemon... Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: ___________ START PLUGINS ___________ Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718179730] CoreMusicLibrary::Adding element Media Servers Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: Cannot find translation for sourceMedia Servers Oct 31 22:09:39 volumio-hbdac2hd-beta3 systemd[1]: mpd.service: Succeeded. Oct 31 22:09:39 volumio-hbdac2hd-beta3 systemd[1]: Stopped Music Player Daemon. Oct 31 22:09:39 volumio-hbdac2hd-beta3 systemd[1]: Starting Music Player Daemon... Oct 31 22:09:39 volumio-hbdac2hd-beta3 volumio[917]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718180017] CoreMusicLibrary::Adding element Last_100 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: Cannot find translation for sourceMedia Servers Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718180028] CoreMusicLibrary::Adding element Webradio Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: Cannot find translation for sourceMedia Servers Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: Completed starting Core Plugins Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: ----- MyVolumio plugins startup ---- Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------------------- Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: adding 96e83335-2be5-4677-99e6-60de2d8f9d56 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio3Beta-hb-xlr-02 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: this is already registered, f7e8c432-202b-4163-9c31-ee97b3701219 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio-boss-01 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: Discovery: this is already registered, 96e83335-2be5-4677-99e6-60de2d8f9d56 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: mDNS: Found device Volumio3Beta-hb-xlr-02 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: MPD Permissions set Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:40 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::getQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1114]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Started UPnP Renderer front-end to MPD. Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1114]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetVisibleSources Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: Listing playlists Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::getQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getQueue Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: Upmpdcli Daemon Started Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Shairport Sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Shairport Sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Shairport Sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: shairport-sync.service: Succeeded. Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1124]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1118]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: shairport-sync.service: Succeeded. Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 31 22:09:41 volumio-hbdac2hd-beta3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1120]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:41 volumio-hbdac2hd-beta3 sudo[1124]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: info: Shairport-Sync Started Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: Error adding Membership: Error: addMembership EINVAL Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: info: Shairport-Sync Started Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: info: Shairport-Sync Started Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:09:42 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:09:42 volumio-hbdac2hd-beta3 mpd[1108]: Oct 31 22:09 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 22:09:42 volumio-hbdac2hd-beta3 mpd[1108]: Oct 31 22:09 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Oct 31 22:09:42 volumio-hbdac2hd-beta3 mpd[1108]: Oct 31 22:09 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Oct 31 22:09:42 volumio-hbdac2hd-beta3 systemd[1]: Started Music Player Daemon. Oct 31 22:09:42 volumio-hbdac2hd-beta3 sudo[1094]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:43 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:09:43 volumio-hbdac2hd-beta3 volumio[1116]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin bluetooth to MyMusic Plugins Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin cd_controller to MyMusic Plugins Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 31 22:09:48 volumio-hbdac2hd-beta3 volumio[1116]: ..................++++ Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: Starting MyVolumio Remote Streaming Endpoints Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: MyVolumio login type: Token Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: Streaming services startup Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Streaming Daemon Oct 31 22:09:51 volumio-hbdac2hd-beta3 sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 31 22:09:51 volumio-hbdac2hd-beta3 sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:51 volumio-hbdac2hd-beta3 systemd[1]: Stopping Volumio Streaming Daemon... Oct 31 22:09:51 volumio-hbdac2hd-beta3 systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM Oct 31 22:09:51 volumio-hbdac2hd-beta3 systemd[1]: volumio-streaming-daemon.service: Succeeded. Oct 31 22:09:51 volumio-hbdac2hd-beta3 systemd[1]: Stopped Volumio Streaming Daemon. Oct 31 22:09:51 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Streaming Daemon. Oct 31 22:09:51 volumio-hbdac2hd-beta3 sudo[1148]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: ############################ Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: # Volumio Streaming Daemon # Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: # Running on port 7777 # Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: ############################ Oct 31 22:09:51 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Environment: production Oct 31 22:09:52 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 31 22:09:52 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO: Adding device Oct 31 22:09:52 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO: Evaluating Server Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Adding audio output: Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO: Adding device Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: MYVOLUMIO: Evaluating Server Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Remote config written successfully Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Tunnel 1 Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Tunnel Connection Checker Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Completed starting MyVolumio Plugin Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Setting Geolocation for MyVolumio to eu2 Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: MyVolumio status changed Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Streaming services startup Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: Re-Starting Streaming Daemon Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Restarting daemon Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Environment: production Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Oct 31 22:09:53 volumio-hbdac2hd-beta3 sudo[1179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 31 22:09:53 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Oct 31 22:09:53 volumio-hbdac2hd-beta3 sudo[1179]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:54 volumio-hbdac2hd-beta3 systemd[1]: Started MyVolumio SSH Tunnel. Oct 31 22:09:54 volumio-hbdac2hd-beta3 sudo[1179]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:54 volumio-hbdac2hd-beta3 autossh[1184]: port set to 0, monitoring disabled Oct 31 22:09:54 volumio-hbdac2hd-beta3 autossh[1184]: starting ssh (count 1) Oct 31 22:09:54 volumio-hbdac2hd-beta3 autossh[1184]: ssh child pid is 1187 Oct 31 22:09:54 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718194607] Starting BluetoothController Oct 31 22:09:54 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Enabled services: Oct 31 22:09:54 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: 1) tidal Oct 31 22:09:54 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: 2) qobuz Oct 31 22:09:54 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Oct 31 22:09:55 volumio-hbdac2hd-beta3 wpa_supplicant[782]: RRM: Ignoring radio measurement request: Not RRM network Oct 31 22:09:56 volumio-hbdac2hd-beta3 wpa_supplicant[782]: RRM: Ignoring radio measurement request: Not RRM network Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumiossh-tunnel[1183]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[188.166.162.121]:2222' (RSA) to the list of known hosts. Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /myvolumio/plugins/audio_interface/multiroom/scripts/check_snapcast Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1189]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1191]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1191]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: info: MultiRoom plugin initialized Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: STOPPING SNAPCLIENT Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Oct 31 22:09:58 volumio-hbdac2hd-beta3 sudo[1208]: pam_unix(sudo:session): session closed for user root Oct 31 22:09:58 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Preparing to generate the ALSA configuration file Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Setting Geolocation for MyVolumio to eu2 Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Updating MyVolumio device info Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Reading ALSA contributions from plugins. Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: SNAPCLIENT STOPPED Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Snap server and client installed Oct 31 22:09:59 volumio-hbdac2hd-beta3 volumio[917]: info: Remote SSH Started Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: Updating MyVolumio device info Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Environment: production Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: Fetching Streaming Services browse cache Oct 31 22:10:00 volumio-hbdac2hd-beta3 volumio[917]: info: Asound.conf file written Oct 31 22:10:00 volumio-hbdac2hd-beta3 sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 31 22:10:00 volumio-hbdac2hd-beta3 sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1211]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: No state is present for card sndrpihifiberry Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: Found hardware: "HifiberryDacplu" "" "" "" "" Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: Hardware is initialized using a generic method Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: No state is present for card sndrpihifiberry Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Output device has changed, restarting MPD Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Output device has changed, restarting Shairport Sync Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1216]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1216]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:01 volumio-hbdac2hd-beta3 systemd[1]: Stopping Music Player Daemon... Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output for this device Oct 31 22:10:01 volumio-hbdac2hd-beta3 systemd[1]: mpd.service: Succeeded. Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output Oct 31 22:10:01 volumio-hbdac2hd-beta3 systemd[1]: Stopped Music Player Daemon. Oct 31 22:10:01 volumio-hbdac2hd-beta3 systemd[1]: Starting Music Player Daemon... Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Adding audio output: Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio-HBDac2HD-Beta3 Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1225]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Adding METAVOLUMIO REST API Endpoints Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Preparing CD Folders Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Adding CD REST API Endpoints Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Starting UDEV Watcher for CD Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: Detecting CD presence with UDEV Oct 31 22:10:01 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 31 22:10:01 volumio-hbdac2hd-beta3 sudo[1225]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: Bluetooth: Core ver 2.22 Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: NET: Registered protocol family 31 Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: Bluetooth: HCI device and connection manager initialized Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: Bluetooth: HCI socket layer initialized Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: Bluetooth: L2CAP socket layer initialized Oct 31 22:10:01 volumio-hbdac2hd-beta3 kernel: Bluetooth: SCO socket layer initialized Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Adding inputs REST Endpoints Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Scanning Audio Inputs Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Checking against Known Cards name Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Adding Server instance for streaming Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: error: Hi Res Audio Failed Login: Missing Login Data Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Oct 31 22:10:02 volumio-hbdac2hd-beta3 sudo[1237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Stopping AccessToken refresher cron Oct 31 22:10:02 volumio-hbdac2hd-beta3 sudo[1237]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:02 volumio-hbdac2hd-beta3 sudo[1237]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: AccessToken refresher cron started Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: Stopping AccessToken refresher cron for QOBUZ Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: AccessToken refresher cron started for QOBUZ Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Environment: production Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio-streaming-daemon[1154]: Environment: production Oct 31 22:10:02 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 195.141.190.190 Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'Volumio-HBDac2HD-Beta3' Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: Can't get device info: No such device Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: MPD Permissions set Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:02 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: Starting Shairport Sync Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: Fetching Streaming Services browse cache Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: CURURI: albums:// Oct 31 22:10:03 volumio-hbdac2hd-beta3 sudo[1250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 22:10:03 volumio-hbdac2hd-beta3 sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: listAlbums - loading Albums from cache Oct 31 22:10:03 volumio-hbdac2hd-beta3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 31 22:10:03 volumio-hbdac2hd-beta3 systemd[1]: shairport-sync.service: Succeeded. Oct 31 22:10:03 volumio-hbdac2hd-beta3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 31 22:10:03 volumio-hbdac2hd-beta3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 31 22:10:03 volumio-hbdac2hd-beta3 sudo[1250]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:03 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 130.60.204.10 Oct 31 22:10:03 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 195.186.1.100 Oct 31 22:10:03 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 156.106.214.52 Oct 31 22:10:03 volumio-hbdac2hd-beta3 volumio[917]: info: Shairport-Sync Started Oct 31 22:10:04 volumio-hbdac2hd-beta3 mpd[1233]: Oct 31 22:10 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1256]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:04 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 185.125.24.59 Oct 31 22:10:04 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 212.25.1.1 Oct 31 22:10:04 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 162.159.200.1 Oct 31 22:10:04 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Bluetooth Module. Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1256]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:04 volumio-hbdac2hd-beta3 mpd[1233]: Oct 31 22:10 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Oct 31 22:10:04 volumio-hbdac2hd-beta3 mpd[1233]: Oct 31 22:10 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Oct 31 22:10:04 volumio-hbdac2hd-beta3 systemd[1]: Started Music Player Daemon. Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1218]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1259]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:04 volumio-hbdac2hd-beta3 volumiobt[1258]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Oct 31 22:10:04 volumio-hbdac2hd-beta3 sudo[1259]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:04 volumio-hbdac2hd-beta3 volumio[917]: info: Volumio BT Module successfully started Oct 31 22:10:05 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:10:05 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 81.94.123.17 Oct 31 22:10:05 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 185.134.196.75 Oct 31 22:10:05 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 46.22.24.205 Oct 31 22:10:05 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 192.33.214.47 Oct 31 22:10:05 volumio-hbdac2hd-beta3 volumio[917]: info: TidalConnect service stoped! Oct 31 22:10:05 volumio-hbdac2hd-beta3 sudo[1268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Oct 31 22:10:05 volumio-hbdac2hd-beta3 sudo[1268]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:05 volumio-hbdac2hd-beta3 volumiobt[1258]: pulseaudio: no process found Oct 31 22:10:05 volumio-hbdac2hd-beta3 sudo[1268]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:05 volumio-hbdac2hd-beta3 volumio[917]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 31 22:10:05 volumio-hbdac2hd-beta3 volumio[917]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 31 22:10:05 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.18' (uid=1000 pid=1272 comm="/usr/bin/pulseaudio ") Oct 31 22:10:05 volumio-hbdac2hd-beta3 systemd[1]: Starting RealtimeKit Scheduling Policy Service... Oct 31 22:10:05 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Oct 31 22:10:05 volumio-hbdac2hd-beta3 systemd[1]: Started RealtimeKit Scheduling Policy Service. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Successfully called chroot. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Successfully dropped privileges. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Successfully limited resources. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Running. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Watchdog thread running. Oct 31 22:10:05 volumio-hbdac2hd-beta3 rtkit-daemon[1273]: Canary thread running. Oct 31 22:10:05 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.19' (uid=0 pid=1273 comm="/usr/lib/rtkit/rtkit-daemon ") Oct 31 22:10:06 volumio-hbdac2hd-beta3 systemd[1]: Starting Authorization Manager... Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: Playing: false Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: VOLATILE: Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: STATE:undefined Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: Playing: false Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: VOLATILE: Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: STATE:undefined Oct 31 22:10:06 volumio-hbdac2hd-beta3 polkitd[1276]: started daemon version 0.105 using authority implementation `local' version `0.105' Oct 31 22:10:06 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 31 22:10:06 volumio-hbdac2hd-beta3 systemd[1]: Started Authorization Manager. Oct 31 22:10:06 volumio-hbdac2hd-beta3 sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 31 22:10:06 volumio-hbdac2hd-beta3 sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:10:06 volumio-hbdac2hd-beta3 systemd[1]: Started Volumio Tidal Connect Service. Oct 31 22:10:06 volumio-hbdac2hd-beta3 sudo[1281]: pam_unix(sudo:session): session closed for user root Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Getting audio outputs on start Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Requesting all other devices output Oct 31 22:10:06 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 195.186.1.101 Oct 31 22:10:06 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 2a02:418:3008:5e37::434 Oct 31 22:10:06 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 84.16.73.33 Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Adding multiroomSync output Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: Adding audio output: Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Adding multiroomSync output Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: Adding audio output: Oct 31 22:10:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output Oct 31 22:10:06 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.39' (uid=1000 pid=1272 comm="/usr/bin/pulseaudio ") Oct 31 22:10:06 volumio-hbdac2hd-beta3 systemd[1]: Starting Bluetooth service... Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: Playing: false Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: VOLATILE: Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: STATE:undefined Oct 31 22:10:07 volumio-hbdac2hd-beta3 pulseaudio[1272]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 31 22:10:07 volumio-hbdac2hd-beta3 pulseaudio[1272]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Applying permissions Oct 31 22:10:07 volumio-hbdac2hd-beta3 bluetoothd[1287]: Bluetooth daemon 5.50 Oct 31 22:10:07 volumio-hbdac2hd-beta3 bluetoothd[1287]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Setting BT discoverable and pairable Oct 31 22:10:07 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Successfully activated service 'org.bluez' Oct 31 22:10:07 volumio-hbdac2hd-beta3 systemd[1]: Started Bluetooth service. Oct 31 22:10:07 volumio-hbdac2hd-beta3 bluetoothd[1287]: Starting SDP server Oct 31 22:10:07 volumio-hbdac2hd-beta3 bluetoothd[1287]: Excluding (cli) sap Oct 31 22:10:07 volumio-hbdac2hd-beta3 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Oct 31 22:10:07 volumio-hbdac2hd-beta3 kernel: Bluetooth: BNEP filters: protocol multicast Oct 31 22:10:07 volumio-hbdac2hd-beta3 kernel: Bluetooth: BNEP socket layer initialized Oct 31 22:10:07 volumio-hbdac2hd-beta3 bluetoothd[1287]: Bluetooth management interface 1.14 initialized Oct 31 22:10:07 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.40' (uid=0 pid=1287 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Oct 31 22:10:07 volumio-hbdac2hd-beta3 pulseaudio[1272]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# -e power on Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Invalid command in menu main: -e Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Use "help" for a list of available commands in a menu. Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Use "menu " if you want to enter any submenu. Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Use "back" if you want to return to menu main. Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# agent on Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Failed to register agent object Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# discoverable on Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: No default controller available Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# pairable on Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: No default controller available Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# agent NoInputNoOutput Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: Failed to register agent object Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# default-agent Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: No agent is registered Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [bluetooth]# quit Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumiobt[1258]: [59B blob data] Oct 31 22:10:07 volumio-hbdac2hd-beta3 systemd[1]: Starting Hostname Service... Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: Executing endpoint tc_getconfig Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 31 22:10:07 volumio-hbdac2hd-beta3 vtcs[1283]: STARTING TidalConnect services, version: 1.1.7.5 Oct 31 22:10:07 volumio-hbdac2hd-beta3 vtcs[1283]: STARTED TidalConnect services. Oct 31 22:10:07 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 212.25.15.129 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: Playing: false Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: VOLATILE: Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: BT PLUGIN MESSAGE: STATE:undefined Oct 31 22:10:07 volumio-hbdac2hd-beta3 dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 31 22:10:07 volumio-hbdac2hd-beta3 systemd[1]: Started Hostname Service. Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: Executing endpoint tc_connect Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: Connecting to TidalConnect. Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:07 volumio-hbdac2hd-beta3 volumio[917]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Oct 31 22:10:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:08 volumio-hbdac2hd-beta3 ntpd[605]: Soliciting pool server 5.148.175.134 Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: info: TidalConnect service started! Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: info: BOOT COMPLETED Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: [Metrics] CommandRouter: 48s 447.37ms Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: xcb_connection_has_error() returned true Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:138:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: aplay: main:828: audio open error: No such device Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: Cannot play startup sound Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::Close All Modals sent Oct 31 22:10:09 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::Close All Modals sent Oct 31 22:10:10 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 22:10:10 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 22:10:10 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 31 22:10:10 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 31 22:10:10 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 31 22:10:36 volumio-hbdac2hd-beta3 ntpd[605]: receive: Unexpected origin timestamp 0xe52992c2.8ccd3185 does not match aorg 0000000000.00000000 from server@195.141.190.190 xmt 0xe52992dc.7bb4c16b Oct 31 22:10:36 volumio-hbdac2hd-beta3 ntpd[605]: receive: Unexpected origin timestamp 0xe52992c2.8cb60651 does not match aorg 0000000000.00000000 from server@46.22.24.205 xmt 0xe52992dc.7b915dca Oct 31 22:10:36 volumio-hbdac2hd-beta3 ntpd[605]: receive: Unexpected origin timestamp 0xe52992c2.8cac7890 does not match aorg 0000000000.00000000 from server@192.33.214.47 xmt 0xe52992dc.7bab1a88 Oct 31 22:10:36 volumio-hbdac2hd-beta3 ntpd[605]: receive: Unexpected origin timestamp 0xe52992c2.8cc1e384 does not match aorg 0000000000.00000000 from server@156.106.214.52 xmt 0xe52992dc.7c5a75fd Oct 31 22:10:38 volumio-hbdac2hd-beta3 volumio[1116]: ......................................................................................++++ Oct 31 22:10:38 volumio-hbdac2hd-beta3 volumio[1116]: e is 65537 (0x010001) Oct 31 22:10:39 volumio-hbdac2hd-beta3 volumio[1116]: writing RSA key Oct 31 22:10:45 volumio-hbdac2hd-beta3 wpa_supplicant[782]: RRM: Ignoring radio measurement request: Not RRM network Oct 31 22:10:46 volumio-hbdac2hd-beta3 wpa_supplicant[782]: RRM: Ignoring radio measurement request: Not RRM network Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::ClearQueue Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::clearPlayQueue Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::addQueueItems Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::addQueueItems Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: Adding Item to queue: albums://Candy%20Dulfer/The%20Essential%20Candy%20Dulfer Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: Exploding uri albums://Candy%20Dulfer/The%20Essential%20Candy%20Dulfer in service mpd Oct 31 22:10:56 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::updateTrackBlock Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrackBlock Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPlay Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index undefined Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::startPlaybackTimer Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::clearAddPlayTracks NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand stop Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand stop took 80 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clear took 61 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand add "NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac" Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 93ms Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand add "NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac" took 88 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand play Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 63ms Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand play took 59 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 91 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clearerror took 106 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 105 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 90 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Lily Was Here","artist":"Candy Dulfer","album":"The Essential Candy Dulfer","uri":"NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac","trackType":"flac"} Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 264ms Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 166 milliseconds Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Lily Was Here","artist":"Candy Dulfer","album":"The Essential Candy Dulfer","uri":"NAS/Musik/Candy Dulfer/The Essential/01 - Lily Was Here.flac","trackType":"flac"} Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:10:57 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 330ms Oct 31 22:10:58 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:58 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:58 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:10:58 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:03 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 31 22:11:03 volumio-hbdac2hd-beta3 systemd[1]: systemd-hostnamed.service: Succeeded. Oct 31 22:11:04 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::ClearQueue Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::clearPlayQueue Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::addQueueItems Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::addQueueItems Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s303413 Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:06 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::updateTrackBlock Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrackBlock Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPlay Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index 0 Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index undefined Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::startPlaybackTimer Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718267239] ControllerWebradio::clearAddPlayTrack Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand stop Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand stop took 32 milliseconds Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 6 milliseconds Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clear took 6 milliseconds Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand load "http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ" Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 9ms Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 21ms Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand add "http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ" Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand add "http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ" took 8 milliseconds Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand play Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 11ms Oct 31 22:11:07 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand play took 4 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 28 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 56 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clearerror took 34 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 32 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ","artist":null,"album":null,"uri":"http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ","trackType":""} Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 117ms Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clearerror took 82 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 79 milliseconds Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ","artist":null,"album":null,"uri":"http://icecast.argovia.ch/vrock?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI2NywiaXNzIjoidGlzcnYifQ.AyTj4NER62O_ajMnb-K9YSZfdj6ksMDJlzgvIPNOcdQ","trackType":""} Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 196ms Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:08 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::ClearQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::clearPlayQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::addQueueItems Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::addQueueItems Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25243 Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::saveQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushQueue Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::updateTrackBlock Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrackBlock Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPlay Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index 0 Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::stop Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: UNSET VOLATILE Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::play index undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::startPlaybackTimer Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: [1635718273481] ControllerWebradio::clearAddPlayTrack Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand stop Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand stop took 36 milliseconds Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 9 milliseconds Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clear took 9 milliseconds Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand load "https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck" Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: error: updateQueue error: null Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 8ms Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 31 22:11:13 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 22ms Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand add "https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck" Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces system playlist update Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: Ignoring MPD Status Update Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand add "https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck" took 6 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand play Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 7ms Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand play took 3 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: ---------------------------- MPD announces state update: player Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::getState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand status Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 25 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand status took 43 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clearerror took 23 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck","artist":null,"album":null,"uri":"https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck","trackType":""} Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:14 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 100ms Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand clearerror took 78 milliseconds Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: sendMpdCommand playlistinfo took 75 milliseconds Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: verbose: ControllerMpd::parseTrackInfo Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: ControllerMpd::pushState Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::servicePushState Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getTrack 0 Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck","artist":null,"album":null,"uri":"https://stream.srg-ssr.ch/m/rsp/mp3_128?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTYzNTcxODI3MywiaXNzIjoidGlzcnYifQ.9Gq5Js_lv5WrDutzMG7vAVtA5_oSQTMYLMLMYivNHck","trackType":""} Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: verbose: CURRENT POSITION 0 Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState stateService pause Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::syncState currentStatus stop Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::pushState Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioPushState Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: ------------------------------ 164ms Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:15 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:37 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetState Oct 31 22:11:37 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::volumioGetQueue Oct 31 22:11:37 volumio-hbdac2hd-beta3 volumio[917]: info: CoreStateMachine::getQueue Oct 31 22:11:37 volumio-hbdac2hd-beta3 volumio[917]: info: CorePlayQueue::getQueue Oct 31 22:11:37 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Oct 31 22:11:42 volumio-hbdac2hd-beta3 volumio[917]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Oct 31 22:11:42 volumio-hbdac2hd-beta3 volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Oct 31 22:11:43 volumio-hbdac2hd-beta3 sudo[1370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Oct 31 22:11:43 volumio-hbdac2hd-beta3 sudo[1370]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 22:11:43 volumio-hbdac2hd-beta3 sudo[1370]: pam_unix(sudo:session): session closed for user root Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output update for this device Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output update for this device Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Pushing multiroomSync output Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:46 volumio-hbdac2hd-beta3 volumio[917]: info: MRS: Updating multiroomSync output Oct 31 22:11:47 volumio-hbdac2hd-beta3 sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Oct 31 22:11:47 volumio-hbdac2hd-beta3 sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0)