Wed Jan 26 15:58:46 UTC 2022 Description="'Noise with PI4/2GB (Rev. 1.5) and Qudelix 5k as USB-DAC'" # cat /proc/version --------------- Linux version 5.10.90-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1512 SMP Thu Jan 13 16:33:39 GMT 2022 # 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="e5f8795c07ba36ff2b02d7ba0a21c7a0f29b897e" VOLUMIO_FE_VERSION="473d8facbed5f9754db84a81b093baace7aa4b64" VOLUMIO_FE3_VERSION="934cddf6d46478e7a53a8d3664cd346f4de7cb34" VOLUMIO_BE_VERSION="359b2717b79cfc72b7d1c918d0fc2885a93bca70" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 24 Jan 2022 10:51:57 AM CET" VOLUMIO_VERSION="3.198" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="74e6a9ad035e912732893c8d6b060b17" # ifconfig --------------- eth0: flags=4099 mtu 1500 ether e4:5f:01:81:9c:ce txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) 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 9808 bytes 1135058 (1.0 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 9808 bytes 1135058 (1.0 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163 mtu 1500 inet 192.168.1.65 netmask 255.255.255.0 broadcast 192.168.1.255 ether e4:5f:01:81:9c:d0 txqueuelen 1000 (Ethernet) RX packets 140169 bytes 205108620 (195.6 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 41022 bytes 4104062 (3.9 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 # sudo iwconfig --------------- lo no wireless extensions. eth0 no wireless extensions. wlan0 IEEE 802.11 ESSID:"icanhearyouhavingsex" Mode:Managed Frequency:2.462 GHz Access Point: 60:E3:27:4F:C2:5D Bit Rate=72.2 Mb/s Tx-Power=31 dBm Retry short limit:7 RTS thr:off Fragment thr:off Encryption key:off Power Management:off Link Quality=49/70 Signal level=-61 dBm Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0 Tx excessive retries:0 Invalid misc:0 Missed beacon:0 # aplay -l --------------- **** List of PLAYBACK Hardware Devices **** card 0: b1 [bcm2835 HDMI 1], device 0: bcm2835 HDMI 1 [bcm2835 HDMI 1] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 1: Headphones [bcm2835 Headphones], device 0: bcm2835 Headphones [bcm2835 Headphones] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 5: DAC [Qudelix-5K USB DAC], device 0: USB Audio [USB Audio] Subdevices: 0/1 Subdevice #0: subdevice #0 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 1 15:49 ? 00:00:07 /sbin/init root 2 0 0 15:49 ? 00:00:00 [kthreadd] root 3 2 0 15:49 ? 00:00:00 [rcu_gp] root 4 2 0 15:49 ? 00:00:00 [rcu_par_gp] root 7 2 0 15:49 ? 00:00:00 [kworker/u8:0-brcmf_wq/mmc1:0001:1] root 8 2 0 15:49 ? 00:00:00 [mm_percpu_wq] root 9 2 0 15:49 ? 00:00:00 [rcu_tasks_rude_] root 10 2 0 15:49 ? 00:00:00 [rcu_tasks_trace] root 11 2 0 15:49 ? 00:00:00 [ksoftirqd/0] root 12 2 0 15:49 ? 00:00:00 [rcu_sched] root 13 2 0 15:49 ? 00:00:00 [migration/0] root 14 2 0 15:49 ? 00:00:00 [cpuhp/0] root 15 2 0 15:49 ? 00:00:00 [cpuhp/1] root 16 2 0 15:49 ? 00:00:00 [migration/1] root 17 2 0 15:49 ? 00:00:00 [ksoftirqd/1] root 20 2 0 15:49 ? 00:00:00 [cpuhp/2] root 21 2 0 15:49 ? 00:00:00 [migration/2] root 22 2 0 15:49 ? 00:00:00 [ksoftirqd/2] root 24 2 0 15:49 ? 00:00:00 [kworker/2:0H-kblockd] root 25 2 0 15:49 ? 00:00:00 [cpuhp/3] root 26 2 0 15:49 ? 00:00:00 [migration/3] root 27 2 0 15:49 ? 00:00:00 [ksoftirqd/3] root 30 2 0 15:49 ? 00:00:00 [kdevtmpfs] root 31 2 0 15:49 ? 00:00:00 [netns] root 32 2 0 15:49 ? 00:00:00 [kworker/0:1-events] root 34 2 0 15:49 ? 00:00:00 [kworker/2:1-mm_percpu_wq] root 35 2 0 15:49 ? 00:00:00 [kauditd] root 36 2 0 15:49 ? 00:00:01 [kworker/0:2-mm_percpu_wq] root 37 2 0 15:49 ? 00:00:00 [khungtaskd] root 38 2 0 15:49 ? 00:00:00 [oom_reaper] root 39 2 0 15:49 ? 00:00:00 [writeback] root 40 2 0 15:49 ? 00:00:00 [kcompactd0] root 60 2 0 15:49 ? 00:00:00 [kblockd] root 61 2 0 15:49 ? 00:00:00 [blkcg_punt_bio] root 62 2 0 15:49 ? 00:00:00 [watchdogd] root 63 2 0 15:49 ? 00:00:00 [kworker/1:1H-kblockd] root 64 2 0 15:49 ? 00:00:00 [rpciod] root 65 2 0 15:49 ? 00:00:00 [kworker/u9:0-hci0] root 66 2 0 15:49 ? 00:00:00 [xprtiod] root 67 2 0 15:49 ? 00:00:00 [kswapd0] root 68 2 0 15:49 ? 00:00:00 [nfsiod] root 69 2 0 15:49 ? 00:00:00 [kthrotld] root 70 2 0 15:49 ? 00:00:00 [kworker/3:1-events_power_efficient] root 71 2 0 15:49 ? 00:00:00 [kworker/1:2-rcu_gp] root 72 2 0 15:49 ? 00:00:00 [iscsi_eh] root 73 2 0 15:49 ? 00:00:00 [iscsi_destroy] root 74 2 0 15:49 ? 00:00:00 [nvme-wq] root 75 2 0 15:49 ? 00:00:00 [nvme-reset-wq] root 76 2 0 15:49 ? 00:00:00 [nvme-delete-wq] root 79 2 0 15:49 ? 00:00:00 [DWC Notificatio] root 80 2 0 15:49 ? 00:00:00 [uas] root 81 2 0 15:49 ? 00:00:05 [kworker/u8:2-brcmf_wq/mmc1:0001:1] root 82 2 0 15:49 ? 00:00:00 [vchiq-slot/0] root 83 2 0 15:49 ? 00:00:00 [vchiq-recy/0] root 84 2 0 15:49 ? 00:00:00 [vchiq-sync/0] root 85 2 0 15:49 ? 00:00:00 [zswap-shrink] root 88 2 0 15:49 ? 00:00:00 [kworker/1:5-mm_percpu_wq] root 89 2 0 15:49 ? 00:00:00 [sdhci] root 90 2 0 15:49 ? 00:00:00 [irq/48-mmc0] root 92 2 0 15:49 ? 00:00:00 [kworker/3:3-events_power_efficient] root 102 2 0 15:49 ? 00:00:00 [mmc_complete] root 103 2 0 15:49 ? 00:00:00 [kworker/3:1H-kblockd] root 104 2 0 15:49 ? 00:00:00 [kworker/0:1H-kblockd] root 125 2 0 15:49 ? 00:00:00 [kworker/1:2H-kblockd] root 129 2 0 15:49 ? 00:00:00 [jbd2/mmcblk0p2-] root 130 2 0 15:49 ? 00:00:00 [ext4-rsv-conver] root 137 2 0 15:49 ? 00:00:01 [loop0] root 164 2 0 15:49 ? 00:00:00 [kworker/3:2H-kblockd] root 165 2 0 15:49 ? 00:00:00 [jbd2/mmcblk0p3-] root 166 2 0 15:49 ? 00:00:00 [ext4-rsv-conver] root 173 2 0 15:49 ? 00:00:00 [ipv6_addrconf] root 188 2 0 15:49 ? 00:00:00 [kworker/0:2H-kblockd] root 203 1 0 15:49 ? 00:00:00 /lib/systemd/systemd-journald root 213 2 0 15:49 ? 00:00:00 [kworker/2:3-mm_percpu_wq] root 222 1 0 15:49 ? 00:00:00 /lib/systemd/systemd-udevd root 253 2 0 15:49 ? 00:00:00 [vchiq-keep/0] root 254 2 0 15:49 ? 00:00:00 [SMIO] root 264 2 0 15:49 ? 00:00:00 [kworker/2:2H-kblockd] root 280 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 281 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 284 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 285 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 288 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 291 2 0 15:49 ? 00:00:00 [mmal-vchiq] root 322 2 0 15:49 ? 00:00:00 [cfg80211] root 323 2 0 15:49 ? 00:00:00 [brcmf_wq/mmc1:0] root 324 2 0 15:49 ? 00:00:00 [brcmf_wdog/mmc1] _rpc 399 1 0 15:49 ? 00:00:00 /sbin/rpcbind -f -w root 405 1 0 15:49 ? 00:00:01 /usr/sbin/haveged --Foreground --verbose=1 -w 1024 message+ 428 1 0 15:49 ? 00:00:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only root 434 1 0 15:49 ? 00:00:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant volumio 440 1 0 15:49 ? 00:00:00 /usr/local/bin/volumio-remote-updater root 441 1 0 15:49 ? 00:00:00 /usr/sbin/alsactl -E HOME=/run/alsa -s -n 19 -c rdaemon avahi 448 1 0 15:49 ? 00:00:00 avahi-daemon: running [volumiokhv.local] nobody 455 1 0 15:49 ? 00:00:00 /usr/sbin/thd --triggers /etc/triggerhappy/triggers.d/ --socket /run/thd.socket --user nobody --deviceglob /dev/input/event* root 457 1 0 15:49 ? 00:00:00 /lib/systemd/systemd-logind avahi 467 448 0 15:49 ? 00:00:00 avahi-daemon: chroot helper shairpo+ 589 1 0 15:50 ? 00:00:00 /usr/bin/shairport-sync --configfile=/tmp/shairport-sync.conf root 593 1 0 15:50 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group ntp 607 1 0 15:50 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 root 608 1 0 15:50 tty1 00:00:00 /sbin/agetty -o -p -- \u --noclear tty1 linux root 612 1 0 15:50 ? 00:00:00 /usr/sbin/ifplugd -i eth0 -q -f -u0 -d10 -w -I root 618 1 0 15:50 ? 00:00:00 /usr/sbin/sshd -D root 625 593 0 15:50 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 668 1 0 15:50 ? 00:00:00 wpa_supplicant -s -B -Dnl80211,wext -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 root 680 1 0 15:50 ? 00:00:00 /sbin/dhcpcd root 691 2 0 15:50 ? 00:00:00 [kworker/u9:1-hci0] root 692 1 0 15:50 ? 00:00:00 /usr/bin/hciattach /dev/serial1 bcm43xx 3000000 flow - root 707 1 0 15:50 ? 00:00:00 /usr/lib/bluetooth/bluetoothd --noplugin=sap volumio 785 1 2 15:50 ? 00:00:14 /usr/bin/node /volumio/index.js root 806 1 0 15:50 ? 00:00:00 /usr/sbin/winbindd --foreground --no-process-group root 809 806 0 15:50 ? 00:00:00 winbindd: domain child [VOLUMIOKHV] root 811 1 0 15:50 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 813 811 0 15:50 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 814 811 0 15:50 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 815 806 0 15:50 ? 00:00:00 winbindd: idmap child root 816 806 0 15:50 ? 00:00:00 winbindd: domain child [BUILTIN] root 818 811 0 15:50 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 861 2 0 15:50 ? 00:00:01 [kworker/u8:3-brcmf_wq/mmc1:0001:1] root 863 2 0 15:50 ? 00:00:00 [cifsiod] root 864 2 0 15:50 ? 00:00:00 [smb3decryptd] root 865 2 0 15:50 ? 00:00:00 [cifsfileinfoput] root 866 2 0 15:50 ? 00:00:00 [cifsoplockd] root 867 2 0 15:50 ? 00:00:00 [cifs-dfscache] root 870 2 0 15:50 ? 00:00:00 [cifsd] root 872 2 0 15:50 ? 00:00:00 [cifsd] root 873 2 0 15:50 ? 00:00:00 [cifsd] volumio 897 785 0 15:50 ? 00:00:00 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 906 897 0 15:50 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 907 897 0 15:50 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 908 897 0 15:50 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 983 1 0 15:50 ? 00:00:00 /usr/bin/spopd -f -c /etc/spopd.conf volumio 987 1 0 15:50 ? 00:00:00 /bin/bash /data/plugins/music_service/volspotconnect2/startconnect.sh volumio 990 987 0 15:50 ? 00:00:00 ./vollibrespot -c volspotify.toml mpd 996 1 2 15:50 ? 00:00:10 /usr/bin/mpd --no-daemon root 1008 2 0 15:50 ? 00:00:00 [irq/64-rotary-e] root 1009 2 0 15:50 ? 00:00:00 [irq/65-rotary-e] volumio 1019 785 0 15:50 ? 00:00:00 /bin/cat /dev/input/by-path/platform-rotary@5-event volumio 1035 1 0 15:50 ? 00:00:01 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf volumio 1073 1 0 15:50 ? 00:00:00 /bin/streaming-daemon volumio 1528 1 0 15:54 ? 00:00:00 /bin/sh /tmp/sshtunnel.sh volumio 1529 1528 0 15:54 ? 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 fzPHMW7dd6SAQ6y39R7zUbaFSXH3-ba34aedf1d4d7ec5b06df8fcfa2ab5e7.eu4.myvolumio.org:8091:localhost:3000 eu4.myvolumio.org volumio 1532 1529 0 15:54 ? 00:00:00 /usr/bin/ssh -o ServerAliveInterval 30 -o ServerAliveCountMax 3 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -N -p 2222 -R fzPHMW7dd6SAQ6y39R7zUbaFSXH3-ba34aedf1d4d7ec5b06df8fcfa2ab5e7.eu4.myvolumio.org:8091:localhost:3000 eu4.myvolumio.org root 1623 2 0 15:55 ? 00:00:00 [kworker/3:0H] root 1628 2 0 15:55 ? 00:00:00 [kworker/3:0-events_power_efficient] root 1631 2 0 15:55 ? 00:00:00 [kworker/0:0-events] root 1905 2 0 15:57 ? 00:00:00 [kworker/2:0-mm_percpu_wq] volumio 2042 785 0 15:58 ? 00:00:00 /bin/sh -c /usr/bin/node /volumio/logsubmit.js 'Noise with PI4/2GB (Rev. 1.5) and Qudelix 5k as USB-DAC' volumio 2043 2042 0 15:58 ? 00:00:00 /usr/bin/node /volumio/logsubmit.js Noise with PI4/2GB (Rev. 1.5) and Qudelix 5k as USB-DAC volumio 2063 2043 0 15:58 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 2064 2063 0 15:58 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.5G 841M 1.5G 37% /imgpart /dev/loop0 364M 364M 0 100% /static overlay 56G 369M 53G 1% / devtmpfs 919M 0 919M 0% /dev tmpfs 959M 12K 959M 1% /dev/shm tmpfs 959M 9.0M 950M 1% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 959M 0 959M 0% /sys/fs/cgroup tmpfs 959M 60K 959M 1% /tmp tmpfs 959M 0 959M 0% /var/spool/cups tmpfs 20M 28K 20M 1% /var/log tmpfs 959M 0 959M 0% /var/spool/cups/tmp /dev/mmcblk0p1 92M 54M 38M 59% /boot //192.168.1.15/musicshare 1.8T 1.3T 587G 68% /mnt/NAS/Musik //192.168.1.15/musicshare_hires 1.8T 1.3T 587G 68% /mnt/NAS/Musik_Hi-Res //192.168.1.15/musicshare_new 1.8T 1.3T 587G 68% /mnt/NAS/Musik_Neu # 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=940828k,nr_inodes=150927,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/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) 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/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/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) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=32,pgrp=1,timeout=0,minproto=5,maxproto=5,direct) sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime) 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) tmpfs on /tmp type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups type tmpfs (rw,noatime,mode=755) tmpfs on /var/log type tmpfs (rw,nodev,relatime,size=20480k,mode=777,uid=1000,gid=4) tmpfs on /var/spool/cups/tmp type tmpfs (rw,noatime,mode=755) /dev/mmcblk0p1 on /boot type vfat (rw,nosuid,nodev,noexec,relatime,fmask=0111,dmask=0000,allow_utime=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,user) //192.168.1.15/musicshare on /mnt/NAS/Musik type cifs (ro,relatime,vers=3.1.1,cache=strict,username=musicshare,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.1.15,file_mode=0666,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=4194304,wsize=4194304,bsize=1048576,echo_interval=60,actimeo=1) //192.168.1.15/musicshare_hires on /mnt/NAS/Musik_Hi-Res type cifs (ro,relatime,vers=3.1.1,cache=strict,username=musicshare,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.1.15,file_mode=0666,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=4194304,wsize=4194304,bsize=1048576,echo_interval=60,actimeo=1) //192.168.1.15/musicshare_new on /mnt/NAS/Musik_Neu type cifs (ro,relatime,vers=3.1.1,cache=strict,username=musicshare,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.1.15,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: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 1035/upmpdcli tcp 0 0 0.0.0.0:35485 0.0.0.0:* LISTEN 990/./vollibrespot 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 1035/upmpdcli tcp 0 0 0.0.0.0:5000 0.0.0.0:* LISTEN - tcp 0 0 127.0.0.1:6602 0.0.0.0:* LISTEN 983/spopd tcp 0 0 0.0.0.0:139 0.0.0.0:* LISTEN - tcp 0 0 127.0.0.1:6602 127.0.0.1:36206 ESTABLISHED 983/spopd tcp 0 0 192.168.1.65:41170 13.32.110.43:80 ESTABLISHED - tcp 0 0 127.0.0.1:40548 127.0.0.1:6600 ESTABLISHED 785/node tcp 0 0 192.168.1.65:42568 167.172.103.77:2222 ESTABLISHED 1532/ssh tcp 0 0 127.0.0.1:36206 127.0.0.1:6602 ESTABLISHED 785/node tcp 0 0 192.168.1.65:55862 192.168.1.15:445 ESTABLISHED - tcp 0 0 192.168.1.65:41950 35.201.97.85:443 ESTABLISHED 785/node tcp 0 0 127.0.0.1:40552 127.0.0.1:6600 ESTABLISHED 785/node tcp 0 0 192.168.1.65:52052 104.199.65.135:4070 ESTABLISHED 983/spopd tcp 0 0 127.0.0.1:37474 127.0.0.1:6599 ESTABLISHED 1035/upmpdcli tcp 0 0 127.0.0.1:46956 127.0.0.1:3000 ESTABLISHED 785/node tcp 0 0 127.0.0.1:6602 127.0.0.1:36204 ESTABLISHED 983/spopd tcp 0 0 192.168.1.65:43594 192.168.1.70:3000 ESTABLISHED 785/node tcp 0 0 192.168.1.65:55860 192.168.1.15:445 ESTABLISHED - tcp 0 0 127.0.0.1:37470 127.0.0.1:6599 ESTABLISHED 1035/upmpdcli tcp 0 0 127.0.0.1:46936 127.0.0.1:3000 ESTABLISHED 440/volumio-remote- tcp 0 0 127.0.0.1:46960 127.0.0.1:3000 ESTABLISHED 785/node tcp 0 0 192.168.1.65:50072 167.172.103.77:443 ESTABLISHED 785/node tcp 0 0 192.168.1.65:37958 84.247.14.230:80 ESTABLISHED 785/node tcp 0 0 192.168.1.65:55858 192.168.1.15:445 ESTABLISHED - tcp 0 0 127.0.0.1:36204 127.0.0.1:6602 ESTABLISHED 785/node tcp 0 0 127.0.0.1:47238 127.0.0.1:3000 ESTABLISHED 785/node tcp6 0 0 :::111 :::* LISTEN - tcp6 0 0 :::22 :::* LISTEN - tcp6 0 0 :::3000 :::* LISTEN 785/node tcp6 0 0 :::3001 :::* LISTEN 897/node tcp6 0 0 :::3005 :::* LISTEN 785/node tcp6 0 0 :::445 :::* LISTEN - tcp6 0 0 :::7777 :::* LISTEN 1073/streaming-daem tcp6 0 0 :::6599 :::* LISTEN 785/node tcp6 0 0 :::5000 :::* LISTEN - tcp6 0 0 :::6600 :::* LISTEN - tcp6 0 0 :::139 :::* LISTEN - tcp6 0 0 192.168.1.65:3000 192.168.1.70:60138 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:6600 127.0.0.1:40552 ESTABLISHED - tcp6 0 0 127.0.0.1:3000 127.0.0.1:46960 ESTABLISHED 785/node tcp6 0 0 192.168.1.65:3000 192.168.1.215:46388 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:6599 127.0.0.1:37474 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:6600 127.0.0.1:40548 ESTABLISHED - tcp6 0 0 127.0.0.1:3000 127.0.0.1:46956 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:6599 127.0.0.1:37470 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:46936 ESTABLISHED 785/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:47238 ESTABLISHED 785/node # cat /etc/asound.conf --------------- pcm.!default { type empty slave.pcm "volumio" } pcm.volumio { 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 "DAC" } # cat /var/log/mpd.log --------------- Jan 26 15:49 : zeroconf: No global port, disabling zeroconf Jan 26 15:49 : zeroconf: No global port, disabling zeroconf Jan 26 15:50 : client: [0] opened from local Jan 26 15:50 : exception: No such directory Jan 26 15:50 : client: [1] opened from local Jan 26 15:50 : zeroconf: No global port, disabling zeroconf Jan 26 15:50 : client: [0] opened from local Jan 26 15:50 : client: [1] opened from local Jan 26 15:50 : client: [2] opened from 127.0.0.1:40548 Jan 26 15:50 : client: [3] opened from 127.0.0.1:40552 Jan 26 15:50 : exception: Failed to read mixer for 'alsa': no such mixer control: PCM Jan 26 15:51 : exception: No such playlist Jan 26 15:51 : exception: Failed to open mixer for 'alsa': no such mixer control: PCM Jan 26 15:54 : player: played "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ" Jan 26 15:54 : exception: No such playlist Jan 26 15:54 : exception: Failed to open mixer for 'alsa': no such mixer control: PCM Jan 26 15:56 : exception: No such playlist Jan 26 15:57 : player: played "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo" # volumio plugin list --------------- This command will list installed plugins on your device ----------------------- Installed Plugins: [ { prettyName: 'Spotify', name: 'spop', category: 'music_service', version: '2.0.3', icon: 'fa-spotify', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'Volumio Spotify Connect2', name: 'volspotconnect2', category: 'music_service', version: '3.0.7', icon: 'fa-spotify', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'System information', name: 'Systeminfo', category: 'user_interface', version: '3.0.0', icon: 'fa-info-circle', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'Rotary Encoder II', name: 'rotaryencoder2', category: 'user_interface', version: '1.0.7', icon: 'fa-circle-o-notch', isManuallyInstalled: true, enabled: true, active: true } ] ------------------------------------------ # cat /data/configuration/plugins.json --------------- { "music_service": { "airplay_emulation": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STOPPED" } }, "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": false }, "status": { "type": "string", "value": "STOPPED" } }, "streaming_services": { "status": { "type": "string", "value": "STARTING" } }, "cd_controller": { "status": { "type": "string", "value": "STOPPED" }, "enabled": { "type": "boolean", "value": false } }, "tidal": { "status": { "type": "string", "value": "STARTED" } }, "qobuz": { "status": { "type": "string", "value": "STARTED" } }, "tidalconnect": { "status": { "type": "string", "value": "STOPPED" }, "enabled": { "type": "boolean", "value": false } }, "spop": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "volspotconnect2": { "enabled": { "type": "boolean", "value": true }, "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": "STOPPED" }, "enabled": { "type": "boolean", "value": false } } }, "miscellanea": { "alarm-clock": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "albumart": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "appearance": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "wizard": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "my_music": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "user_interface": { "websocket": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "mpdemulation": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STARTED" } }, "rest_api": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "Systeminfo": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "rotaryencoder2": { "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 ################################################################ decoder { plugin "faad" enabled "no" } ############################################################################### # 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 "4096" ############################################################################### # 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, 332 ms: OK https://www.googleapis.com, 195 ms: OK https://securetoken.googleapis.com, 353 ms: OK https://myvolumio.firebaseio.com, 577 ms: OK https://functions.volumio.cloud, 706 ms: OK https://oauth-performer.dfs.volumio.org, 2431 ms: OK https://browsing-performer.dfs.volumio.org, 653 ms: OK http://cddb.volumio.org, 604 ms: OK https://functions.volumio.cloud, 550 ms: OK http://pushupdates.volumio.org, 212 ms: OK http://plugins.volumio.org, 1139 ms: OK https://database.volumio.cloud, 698 ms: OK https://radio-directory.firebaseapp.com, 469 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 Wed 2022-01-26 15:58:52 UTC. -- Feb 14 10:11:59 volumiokhv kernel: Booting Linux on physical CPU 0x0 Feb 14 10:11:59 volumiokhv kernel: Linux version 5.10.90-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1512 SMP Thu Jan 13 16:33:39 GMT 2022 Feb 14 10:11:59 volumiokhv kernel: CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d Feb 14 10:11:59 volumiokhv kernel: CPU: div instructions available: patching division code Feb 14 10:11:59 volumiokhv kernel: CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache Feb 14 10:11:59 volumiokhv kernel: OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.5 Feb 14 10:11:59 volumiokhv kernel: random: fast init done Feb 14 10:11:59 volumiokhv kernel: Memory policy: Data cache writealloc Feb 14 10:11:59 volumiokhv kernel: Reserved memory: created CMA memory pool at 0x000000002a000000, size 64 MiB Feb 14 10:11:59 volumiokhv kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Feb 14 10:11:59 volumiokhv kernel: Zone ranges: Feb 14 10:11:59 volumiokhv kernel: DMA [mem 0x0000000000000000-0x000000002fffffff] Feb 14 10:11:59 volumiokhv kernel: Normal empty Feb 14 10:11:59 volumiokhv kernel: HighMem [mem 0x0000000030000000-0x000000007fffffff] Feb 14 10:11:59 volumiokhv kernel: Movable zone start for each node Feb 14 10:11:59 volumiokhv kernel: Early memory node ranges Feb 14 10:11:59 volumiokhv kernel: node 0: [mem 0x0000000000000000-0x000000003dffffff] Feb 14 10:11:59 volumiokhv kernel: node 0: [mem 0x0000000040000000-0x000000007fffffff] Feb 14 10:11:59 volumiokhv kernel: Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff] Feb 14 10:11:59 volumiokhv kernel: On node 0 totalpages: 516096 Feb 14 10:11:59 volumiokhv kernel: DMA zone: 1728 pages used for memmap Feb 14 10:11:59 volumiokhv kernel: DMA zone: 0 pages reserved Feb 14 10:11:59 volumiokhv kernel: DMA zone: 196608 pages, LIFO batch:63 Feb 14 10:11:59 volumiokhv kernel: HighMem zone: 319488 pages, LIFO batch:63 Feb 14 10:11:59 volumiokhv kernel: percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920 Feb 14 10:11:59 volumiokhv kernel: pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096 Feb 14 10:11:59 volumiokhv kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Feb 14 10:11:59 volumiokhv kernel: Built 1 zonelists, mobility grouping on. Total pages: 514368 Feb 14 10:11:59 volumiokhv kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=E4:5F:01:81:9C:CE 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=ttyS0,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=0 Feb 14 10:11:59 volumiokhv kernel: Kernel parameter elevator= does not have any effect anymore. Please use sysfs to set IO scheduler for individual devices. Feb 14 10:11:59 volumiokhv kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Feb 14 10:11:59 volumiokhv kernel: software IO TLB: mapped [mem 0x0000000024e00000-0x0000000028e00000] (64MB) Feb 14 10:11:59 volumiokhv kernel: Memory: 1881660K/2064384K available (10240K kernel code, 1366K rwdata, 3192K rodata, 2048K init, 882K bss, 117188K reserved, 65536K cma-reserved, 1277952K highmem) Feb 14 10:11:59 volumiokhv kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Feb 14 10:11:59 volumiokhv kernel: ftrace: allocating 34359 entries in 101 pages Feb 14 10:11:59 volumiokhv kernel: ftrace: allocated 101 pages with 4 groups Feb 14 10:11:59 volumiokhv kernel: rcu: Hierarchical RCU implementation. Feb 14 10:11:59 volumiokhv kernel: Rude variant of Tasks RCU enabled. Feb 14 10:11:59 volumiokhv kernel: Tracing variant of Tasks RCU enabled. Feb 14 10:11:59 volumiokhv kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Feb 14 10:11:59 volumiokhv kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Feb 14 10:11:59 volumiokhv kernel: GIC: Using split EOI/Deactivate mode Feb 14 10:11:59 volumiokhv kernel: random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1 Feb 14 10:11:59 volumiokhv kernel: sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns Feb 14 10:11:59 volumiokhv kernel: clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns Feb 14 10:11:59 volumiokhv kernel: bcm2835: system timer (irq = 25) Feb 14 10:11:59 volumiokhv kernel: arch_timer: cp15 timer(s) running at 54.00MHz (phys). Feb 14 10:11:59 volumiokhv kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns Feb 14 10:11:59 volumiokhv kernel: sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns Feb 14 10:11:59 volumiokhv kernel: Switching to timer-based delay loop, resolution 18ns Feb 14 10:11:59 volumiokhv kernel: Console: colour dummy device 80x30 Feb 14 10:11:59 volumiokhv kernel: printk: console [tty1] enabled Feb 14 10:11:59 volumiokhv kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) Feb 14 10:11:59 volumiokhv kernel: pid_max: default: 32768 minimum: 301 Feb 14 10:11:59 volumiokhv kernel: LSM: Security Framework initializing Feb 14 10:11:59 volumiokhv kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: cgroup: Disabling memory control group subsystem Feb 14 10:11:59 volumiokhv kernel: CPU: Testing write buffer coherency: ok Feb 14 10:11:59 volumiokhv kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Feb 14 10:11:59 volumiokhv kernel: Setting up static identity map for 0x200000 - 0x20003c Feb 14 10:11:59 volumiokhv kernel: rcu: Hierarchical SRCU implementation. Feb 14 10:11:59 volumiokhv kernel: smp: Bringing up secondary CPUs ... Feb 14 10:11:59 volumiokhv kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Feb 14 10:11:59 volumiokhv kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Feb 14 10:11:59 volumiokhv kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Feb 14 10:11:59 volumiokhv kernel: smp: Brought up 1 node, 4 CPUs Feb 14 10:11:59 volumiokhv kernel: SMP: Total of 4 processors activated (432.00 BogoMIPS). Feb 14 10:11:59 volumiokhv kernel: CPU: All CPU(s) started in HYP mode. Feb 14 10:11:59 volumiokhv kernel: CPU: Virtualization extensions available. Feb 14 10:11:59 volumiokhv kernel: devtmpfs: initialized Feb 14 10:11:59 volumiokhv kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 Feb 14 10:11:59 volumiokhv kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Feb 14 10:11:59 volumiokhv kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: pinctrl core: initialized pinctrl subsystem Feb 14 10:11:59 volumiokhv kernel: NET: Registered protocol family 16 Feb 14 10:11:59 volumiokhv kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Feb 14 10:11:59 volumiokhv kernel: audit: initializing netlink subsys (disabled) Feb 14 10:11:59 volumiokhv kernel: audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Feb 14 10:11:59 volumiokhv kernel: thermal_sys: Registered thermal governor 'step_wise' Feb 14 10:11:59 volumiokhv kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Feb 14 10:11:59 volumiokhv kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Feb 14 10:11:59 volumiokhv kernel: Serial: AMBA PL011 UART driver Feb 14 10:11:59 volumiokhv kernel: bcm2835-mbox fe00b880.mailbox: mailbox enabled Feb 14 10:11:59 volumiokhv kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2022-01-06T15:39:30, variant start Feb 14 10:11:59 volumiokhv kernel: raspberrypi-firmware soc:firmware: Firmware hash is 58e03c94953762222f2b838390dde54d46c38381 Feb 14 10:11:59 volumiokhv kernel: Kprobes globally optimized Feb 14 10:11:59 volumiokhv kernel: bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 Feb 14 10:11:59 volumiokhv kernel: vgaarb: loaded Feb 14 10:11:59 volumiokhv kernel: SCSI subsystem initialized Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new interface driver usbfs Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new interface driver hub Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new device driver usb Feb 14 10:11:59 volumiokhv kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Feb 14 10:11:59 volumiokhv kernel: clocksource: Switched to clocksource arch_sys_counter Feb 14 10:11:59 volumiokhv kernel: VFS: Disk quotas dquot_6.6.0 Feb 14 10:11:59 volumiokhv kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Feb 14 10:11:59 volumiokhv kernel: FS-Cache: Loaded Feb 14 10:11:59 volumiokhv kernel: CacheFiles: Loaded Feb 14 10:11:59 volumiokhv kernel: NET: Registered protocol family 2 Feb 14 10:11:59 volumiokhv kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: TCP: Hash tables configured (established 8192 bind 8192) Feb 14 10:11:59 volumiokhv kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Feb 14 10:11:59 volumiokhv kernel: NET: Registered protocol family 1 Feb 14 10:11:59 volumiokhv kernel: RPC: Registered named UNIX socket transport module. Feb 14 10:11:59 volumiokhv kernel: RPC: Registered udp transport module. Feb 14 10:11:59 volumiokhv kernel: RPC: Registered tcp transport module. Feb 14 10:11:59 volumiokhv kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Feb 14 10:11:59 volumiokhv kernel: PCI: CLS 0 bytes, default 64 Feb 14 10:11:59 volumiokhv kernel: Trying to unpack rootfs image as initramfs... Feb 14 10:11:59 volumiokhv kernel: Freeing initrd memory: 13028K Feb 14 10:11:59 volumiokhv kernel: Initialise system trusted keyrings Feb 14 10:11:59 volumiokhv kernel: workingset: timestamp_bits=14 max_order=19 bucket_order=5 Feb 14 10:11:59 volumiokhv kernel: zbud: loaded Feb 14 10:11:59 volumiokhv kernel: FS-Cache: Netfs 'nfs' registered for caching Feb 14 10:11:59 volumiokhv kernel: NFS: Registering the id_resolver key type Feb 14 10:11:59 volumiokhv kernel: Key type id_resolver registered Feb 14 10:11:59 volumiokhv kernel: Key type id_legacy registered Feb 14 10:11:59 volumiokhv kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Feb 14 10:11:59 volumiokhv kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Feb 14 10:11:59 volumiokhv kernel: Key type asymmetric registered Feb 14 10:11:59 volumiokhv kernel: Asymmetric key parser 'x509' registered Feb 14 10:11:59 volumiokhv kernel: bounce: pool size: 64 pages Feb 14 10:11:59 volumiokhv kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) Feb 14 10:11:59 volumiokhv kernel: io scheduler mq-deadline registered Feb 14 10:11:59 volumiokhv kernel: io scheduler kyber registered Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x007fffffff -> 0x0400000000 Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) Feb 14 10:11:59 volumiokhv kernel: brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 Feb 14 10:11:59 volumiokhv kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Feb 14 10:11:59 volumiokhv kernel: pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) Feb 14 10:11:59 volumiokhv kernel: pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 Feb 14 10:11:59 volumiokhv kernel: pci 0000:00:00.0: PME# supported from D0 D3hot Feb 14 10:11:59 volumiokhv kernel: PCI: bus0: Fast back to back transfers disabled Feb 14 10:11:59 volumiokhv kernel: pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 Feb 14 10:11:59 volumiokhv kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] Feb 14 10:11:59 volumiokhv kernel: pci 0000:01:00.0: PME# supported from D0 D3hot Feb 14 10:11:59 volumiokhv kernel: PCI: bus1: Fast back to back transfers disabled Feb 14 10:11:59 volumiokhv kernel: pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] Feb 14 10:11:59 volumiokhv kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] Feb 14 10:11:59 volumiokhv kernel: pci 0000:00:00.0: PCI bridge to [bus 01] Feb 14 10:11:59 volumiokhv kernel: pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] Feb 14 10:11:59 volumiokhv kernel: pcieport 0000:00:00.0: enabling device (0140 -> 0142) Feb 14 10:11:59 volumiokhv kernel: pcieport 0000:00:00.0: PME: Signaling with IRQ 62 Feb 14 10:11:59 volumiokhv kernel: bcm2708_fb soc:fb: FB found 1 display(s) Feb 14 10:11:59 volumiokhv kernel: Console: switching to colour frame buffer device 80x30 Feb 14 10:11:59 volumiokhv kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Feb 14 10:11:59 volumiokhv kernel: iproc-rng200 fe104000.rng: hwrng registered Feb 14 10:11:59 volumiokhv kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Feb 14 10:11:59 volumiokhv kernel: gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 Feb 14 10:11:59 volumiokhv kernel: brd: module loaded Feb 14 10:11:59 volumiokhv kernel: loop: module loaded Feb 14 10:11:59 volumiokhv kernel: Loading iSCSI transport class v2.0-870. Feb 14 10:11:59 volumiokhv kernel: libphy: Fixed MDIO Bus: probed Feb 14 10:11:59 volumiokhv kernel: bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 Feb 14 10:11:59 volumiokhv kernel: libphy: bcmgenet MII bus: probed Feb 14 10:11:59 volumiokhv kernel: unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new interface driver r8152 Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new interface driver lan78xx Feb 14 10:11:59 volumiokhv kernel: usbcore: registered new interface driver smsc95xx Feb 14 10:11:59 volumiokhv kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Feb 14 10:11:59 volumiokhv kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 Feb 14 10:11:59 volumiokhv kernel: xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00000e0000000890 Feb 14 10:11:59 volumiokhv kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 Feb 14 10:11:59 volumiokhv kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 14 10:11:59 volumiokhv kernel: usb usb1: Product: xHCI Host Controller Feb 14 10:11:59 volumiokhv kernel: usb usb1: Manufacturer: Linux 5.10.90-v7l+ xhci-hcd Feb 14 10:11:59 volumiokhv kernel: usb usb1: SerialNumber: 0000:01:00.0 Feb 14 10:11:59 volumiokhv kernel: hub 1-0:1.0: USB hub found Feb 14 10:11:59 volumiokhv kernel: hub 1-0:1.0: 1 port detected Feb 14 10:11:59 volumiokhv kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller Feb 14 10:11:59 volumiokhv kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 Jan 26 15:49:32 volumiokhv kernel: xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed Jan 26 15:49:32 volumiokhv kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 Jan 26 15:49:32 volumiokhv kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Jan 26 15:49:32 volumiokhv kernel: usb usb2: Product: xHCI Host Controller Jan 26 15:49:32 volumiokhv kernel: usb usb2: Manufacturer: Linux 5.10.90-v7l+ xhci-hcd Jan 26 15:49:32 volumiokhv kernel: usb usb2: SerialNumber: 0000:01:00.0 Jan 26 15:49:32 volumiokhv kernel: hub 2-0:1.0: USB hub found Jan 26 15:49:32 volumiokhv kernel: hub 2-0:1.0: 4 ports detected Jan 26 15:49:32 volumiokhv kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Jan 26 15:49:32 volumiokhv kernel: dwc_otg: FIQ enabled Jan 26 15:49:32 volumiokhv kernel: dwc_otg: NAK holdoff enabled Jan 26 15:49:32 volumiokhv kernel: dwc_otg: FIQ split-transaction FSM enabled Jan 26 15:49:32 volumiokhv kernel: Module dwc_common_port init Jan 26 15:49:32 volumiokhv kernel: usbcore: registered new interface driver uas Jan 26 15:49:32 volumiokhv kernel: usbcore: registered new interface driver usb-storage Jan 26 15:49:32 volumiokhv kernel: mousedev: PS/2 mouse device common for all mice Jan 26 15:49:32 volumiokhv kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Jan 26 15:49:32 volumiokhv kernel: sdhci: Secure Digital Host Controller Interface driver Jan 26 15:49:32 volumiokhv kernel: sdhci: Copyright(c) Pierre Ossman Jan 26 15:49:32 volumiokhv kernel: mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe Jan 26 15:49:32 volumiokhv kernel: sdhci-pltfm: SDHCI platform and OF driver helper Jan 26 15:49:32 volumiokhv kernel: ledtrig-cpu: registered to indicate activity on CPUs Jan 26 15:49:32 volumiokhv kernel: hid: raw HID events driver (C) Jiri Kosina Jan 26 15:49:32 volumiokhv kernel: usbcore: registered new interface driver usbhid Jan 26 15:49:32 volumiokhv kernel: usbhid: USB HID core driver Jan 26 15:49:32 volumiokhv kernel: Initializing XFRM netlink socket Jan 26 15:49:32 volumiokhv kernel: NET: Registered protocol family 17 Jan 26 15:49:32 volumiokhv kernel: Key type dns_resolver registered Jan 26 15:49:32 volumiokhv kernel: Registering SWP/SWPB emulation handler Jan 26 15:49:32 volumiokhv kernel: registered taskstats version 1 Jan 26 15:49:32 volumiokhv kernel: Loading compiled-in X.509 certificates Jan 26 15:49:32 volumiokhv kernel: Key type ._fscrypt registered Jan 26 15:49:32 volumiokhv kernel: Key type .fscrypt registered Jan 26 15:49:32 volumiokhv kernel: Key type fscrypt-provisioning registered Jan 26 15:49:32 volumiokhv kernel: uart-pl011 fe201000.serial: there is not valid maps for state default Jan 26 15:49:32 volumiokhv kernel: uart-pl011 fe201000.serial: cts_event_workaround enabled Jan 26 15:49:32 volumiokhv kernel: fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 Jan 26 15:49:32 volumiokhv kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Jan 26 15:49:32 volumiokhv kernel: mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 Jan 26 15:49:32 volumiokhv kernel: mmc-bcm2835 fe300000.mmcnr: DMA channel allocated Jan 26 15:49:32 volumiokhv kernel: of_cfs_init Jan 26 15:49:32 volumiokhv kernel: of_cfs_init: OK Jan 26 15:49:32 volumiokhv kernel: mmc1: queuing unknown CIS tuple 0x80 (2 bytes) Jan 26 15:49:32 volumiokhv kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 26 15:49:32 volumiokhv kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 26 15:49:32 volumiokhv kernel: mmc1: queuing unknown CIS tuple 0x80 (7 bytes) Jan 26 15:49:32 volumiokhv kernel: mmc1: queuing unknown CIS tuple 0x80 (3 bytes) Jan 26 15:49:32 volumiokhv kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA Jan 26 15:49:32 volumiokhv kernel: Freeing unused kernel memory: 2048K Jan 26 15:49:32 volumiokhv kernel: Run /init as init process Jan 26 15:49:32 volumiokhv kernel: with arguments: Jan 26 15:49:32 volumiokhv kernel: /init Jan 26 15:49:32 volumiokhv kernel: splash Jan 26 15:49:32 volumiokhv kernel: with environment: Jan 26 15:49:32 volumiokhv kernel: HOME=/ Jan 26 15:49:32 volumiokhv kernel: TERM=linux Jan 26 15:49:32 volumiokhv kernel: imgpart=/dev/mmcblk0p2 Jan 26 15:49:32 volumiokhv kernel: imgfile=/volumio_current.sqsh Jan 26 15:49:32 volumiokhv kernel: bootdelay=5 Jan 26 15:49:32 volumiokhv kernel: mmc1: new high speed SDIO card at address 0001 Jan 26 15:49:32 volumiokhv kernel: mmc0: new ultra high speed DDR50 SDXC card at address 0001 Jan 26 15:49:32 volumiokhv kernel: mmcblk0: mmc0:0001 EC2QT 59.6 GiB Jan 26 15:49:32 volumiokhv kernel: mmcblk0: p1 p2 p3 Jan 26 15:49:32 volumiokhv kernel: usb 1-1: new high-speed USB device number 2 using xhci_hcd Jan 26 15:49:32 volumiokhv initramfs: Booting Volumio for BCM2711 Jan 26 15:49:32 volumiokhv initramfs: This script mounts rootfs RO with an overlay RW layer. Jan 26 15:49:32 volumiokhv kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Jan 26 15:49:32 volumiokhv initramfs: IMGPART=/dev/mmcblk0p2 Jan 26 15:49:32 volumiokhv initramfs: IMGFILE=/volumio_current.sqsh Jan 26 15:49:32 volumiokhv initramfs: Boot delay (except first time) will be 5 seconds Jan 26 15:49:32 volumiokhv initramfs: /dev/mmcblk0p2: Jan 26 15:49:32 volumiokhv kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 Jan 26 15:49:32 volumiokhv kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Jan 26 15:49:32 volumiokhv kernel: usb 1-1: Product: USB2.0 Hub Jan 26 15:49:32 volumiokhv kernel: hub 1-1:1.0: USB hub found Jan 26 15:49:32 volumiokhv kernel: hub 1-1:1.0: 4 ports detected Jan 26 15:49:32 volumiokhv kernel: EXT4-fs (mmcblk0p2): recovery complete Jan 26 15:49:32 volumiokhv kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Jan 26 15:49:32 volumiokhv initramfs: Doing a 5 second delay here to give kernel load a headstart Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2: new full-speed USB device number 3 using xhci_hcd Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2: New USB device found, idVendor=0a12, idProduct=4010, bcdDevice=16.69 Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Jan 26 15:49:32 volumiokhv kernel: hub 1-1.2:1.0: USB hub found Jan 26 15:49:32 volumiokhv kernel: hub 1-1.2:1.0: 4 ports detected Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: new full-speed USB device number 4 using xhci_hcd Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: New USB device found, idVendor=0a12, idProduct=4007, bcdDevice=19.70 Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: New USB device strings: Mfr=1, Product=8, SerialNumber=3 Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: Product: Qudelix-5K USB DAC Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: Manufacturer: QTIL Jan 26 15:49:32 volumiokhv kernel: usb 1-1.2.1: SerialNumber: ABCDEF0123456789 Jan 26 15:49:32 volumiokhv kernel: hid-generic 0003:0A12:4007.0001: hiddev96,hidraw0: USB HID v1.11 Device [QTIL Qudelix-5K USB DAC] on usb-0000:01:00.0-1.2.1/input2 Jan 26 15:49:32 volumiokhv initramfs: Checking for USB updates Jan 26 15:49:32 volumiokhv initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Jan 26 15:49:32 volumiokhv kernel: EXT4-fs (mmcblk0p3): recovery complete Jan 26 15:49:32 volumiokhv kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Jan 26 15:49:32 volumiokhv initramfs: With Option: Jan 26 15:49:32 volumiokhv initramfs: VOLUMIO_VERSION="3.198" Jan 26 15:49:32 volumiokhv initramfs: Finish initramfs, continue booting Volumio Jan 26 15:49:32 volumiokhv systemd[1]: System time before build time, advancing clock. Jan 26 15:49:32 volumiokhv kernel: NET: Registered protocol family 10 Jan 26 15:49:32 volumiokhv kernel: Segment Routing with IPv6 Jan 26 15:49:32 volumiokhv 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) Jan 26 15:49:32 volumiokhv systemd[1]: Detected architecture arm. Jan 26 15:49:32 volumiokhv systemd[1]: Set hostname to . Jan 26 15:49:32 volumiokhv 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. Jan 26 15:49:32 volumiokhv kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 26 15:49:32 volumiokhv kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 26 15:49:32 volumiokhv kernel: random: systemd: uninitialized urandom read (16 bytes read) Jan 26 15:49:32 volumiokhv systemd[1]: Listening on RPCbind Server Activation Socket. Jan 26 15:49:32 volumiokhv systemd[1]: Listening on udev Control Socket. Jan 26 15:49:32 volumiokhv systemd[1]: Reached target System Time Synchronized. Jan 26 15:49:32 volumiokhv systemd[1]: Created slice system-getty.slice. Jan 26 15:49:32 volumiokhv systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. Jan 26 15:49:32 volumiokhv systemd[1]: Listening on Journal Socket. Jan 26 15:49:32 volumiokhv kernel: i2c /dev entries driver Jan 26 15:49:32 volumiokhv systemd-journald[203]: Journal started Jan 26 15:49:32 volumiokhv systemd-journald[203]: Runtime journal (/run/log/journal/9000709e8eac568c03f3269561e57ffc) is 7.5M, max 30.0M, 22.5M free. Jan 26 15:49:32 volumiokhv systemd-modules-load[202]: Inserted module 'i2c_dev' Jan 26 15:49:32 volumiokhv fake-hwclock[204]: Wed Jan 26 15:49:32 UTC 2022 Jan 26 15:49:32 volumiokhv systemd[1]: Starting Create Static Device Nodes in /dev... Jan 26 15:49:32 volumiokhv systemd[1]: Started Create Static Device Nodes in /dev. Jan 26 15:49:32 volumiokhv systemd[1]: Starting udev Kernel Device Manager... Jan 26 15:49:32 volumiokhv systemd[1]: Reached target Local File Systems (Pre). Jan 26 15:49:32 volumiokhv systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Jan 26 15:49:32 volumiokhv systemd[1]: Mounting /tmp... Jan 26 15:49:32 volumiokhv systemd[1]: Mounting /var/spool/cups... Jan 26 15:49:32 volumiokhv systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Jan 26 15:49:32 volumiokhv systemd[1]: Mounting /var/log... Jan 26 15:49:32 volumiokhv systemd[1]: Mounted /tmp. Jan 26 15:49:32 volumiokhv systemd[1]: Mounted /var/spool/cups. Jan 26 15:49:32 volumiokhv systemd[1]: Mounting /var/spool/cups/tmp... Jan 26 15:49:32 volumiokhv systemd-udevd[222]: Network interface NamePolicy= disabled on kernel command line, ignoring. Jan 26 15:49:32 volumiokhv systemd[1]: Mounted /var/log. Jan 26 15:49:32 volumiokhv systemd[1]: Starting Flush Journal to Persistent Storage... Jan 26 15:49:32 volumiokhv systemd[1]: Mounted /var/spool/cups/tmp. Jan 26 15:49:32 volumiokhv systemd[1]: Started udev Coldplug all Devices. Jan 26 15:49:32 volumiokhv systemd[1]: Starting Helper to synchronize boot up for ifupdown... Jan 26 15:49:32 volumiokhv systemd[1]: Started udev Kernel Device Manager. Jan 26 15:49:32 volumiokhv systemd[1]: Starting Show Plymouth Boot Screen... Jan 26 15:49:32 volumiokhv systemd[1]: Started Helper to synchronize boot up for ifupdown. Jan 26 15:49:32 volumiokhv systemd-journald[203]: Runtime journal (/run/log/journal/9000709e8eac568c03f3269561e57ffc) is 7.5M, max 30.0M, 22.5M free. Jan 26 15:49:32 volumiokhv systemd[1]: Received SIGRTMIN+20 from PID 245 (plymouthd). Jan 26 15:49:32 volumiokhv systemd[1]: Started Flush Journal to Persistent Storage. Jan 26 15:49:32 volumiokhv systemd[1]: Started Show Plymouth Boot Screen. Jan 26 15:49:32 volumiokhv systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 26 15:49:32 volumiokhv systemd[1]: Reached target Paths. Jan 26 15:49:32 volumiokhv systemd[1]: Reached target Local Encrypted Volumes. Jan 26 15:49:32 volumiokhv systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Jan 26 15:49:32 volumiokhv systemd-udevd[234]: Using default interface naming scheme 'v240'. Jan 26 15:49:32 volumiokhv kernel: rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 Jan 26 15:49:32 volumiokhv kernel: rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 Jan 26 15:49:32 volumiokhv kernel: rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 Jan 26 15:49:32 volumiokhv kernel: rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 Jan 26 15:49:32 volumiokhv systemd-udevd[234]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 26 15:49:32 volumiokhv kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:32 volumiokhv kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Jan 26 15:49:32 volumiokhv kernel: [vc_sm_connected_init]: start Jan 26 15:49:32 volumiokhv kernel: [vc_sm_connected_init]: installed successfully Jan 26 15:49:32 volumiokhv kernel: mc: Linux media interface: v0.10 Jan 26 15:49:32 volumiokhv kernel: videodev: Linux video capture interface: v2.00 Jan 26 15:49:32 volumiokhv kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:32 volumiokhv kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:32 volumiokhv kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:32 volumiokhv kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Jan 26 15:49:32 volumiokhv kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Jan 26 15:49:32 volumiokhv kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Jan 26 15:49:32 volumiokhv kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Jan 26 15:49:32 volumiokhv kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 26 15:49:32 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Jan 26 15:49:33 volumiokhv kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Jan 26 15:49:33 volumiokhv kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Jan 26 15:49:33 volumiokhv kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Jan 26 15:49:33 volumiokhv kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Jan 26 15:49:33 volumiokhv kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Jan 26 15:49:33 volumiokhv kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Jan 26 15:49:33 volumiokhv kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 26 15:49:33 volumiokhv kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Jan 26 15:49:33 volumiokhv kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Jan 26 15:49:33 volumiokhv kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Jan 26 15:49:33 volumiokhv kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Jan 26 15:49:33 volumiokhv kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 26 15:49:33 volumiokhv kernel: usbcore: registered new interface driver brcmfmac Jan 26 15:49:33 volumiokhv systemd-udevd[242]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 26 15:49:33 volumiokhv kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 26 15:49:33 volumiokhv kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Jan 26 15:49:33 volumiokhv 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 Jan 26 15:49:34 volumiokhv systemd-udevd[243]: Using default interface naming scheme 'v240'. Jan 26 15:49:34 volumiokhv systemd-udevd[243]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Jan 26 15:49:34 volumiokhv kernel: snd_usb_audio: unknown parameter 'nrpacks' ignored Jan 26 15:49:34 volumiokhv systemd[1]: Found device /dev/mmcblk0p1. Jan 26 15:49:34 volumiokhv kernel: usbcore: registered new interface driver snd-usb-audio Jan 26 15:49:35 volumiokhv systemd-udevd[242]: Process '/bin/bash -c '/usr/local/bin/volumio usbattach'' failed with exit code 7. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in /sys/subsystem/net/devices/wlan0 being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in FUSE Control File System being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in Huge Pages File System being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Jan 26 15:49:35 volumiokhv systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Jan 26 15:49:35 volumiokhv systemd[1]: Starting File System Check on /dev/mmcblk0p1... Jan 26 15:49:35 volumiokhv systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 26 15:49:35 volumiokhv systemd[1]: Started File System Check Daemon to report status. Jan 26 15:49:35 volumiokhv systemd[1]: Started Load/Save RF Kill Switch Status. Jan 26 15:49:36 volumiokhv systemd-fsck[361]: fsck.fat 4.1 (2017-01-24) Jan 26 15:49:36 volumiokhv systemd-fsck[361]: /dev/mmcblk0p1: 293 files, 27480/46774 clusters Jan 26 15:49:36 volumiokhv systemd[1]: Started File System Check on /dev/mmcblk0p1. Jan 26 15:49:36 volumiokhv systemd[1]: Mounting /boot... Jan 26 15:49:36 volumiokhv systemd[1]: Mounted /boot. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Local File Systems. Jan 26 15:49:36 volumiokhv systemd[1]: Starting Create Volatile Files and Directories... Jan 26 15:49:36 volumiokhv systemd[1]: Started ifup for eth0. Jan 26 15:49:36 volumiokhv systemd[1]: Starting Preprocess NFS configuration... Jan 26 15:49:36 volumiokhv systemd[1]: Starting Raise network interfaces... Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Started ifup for wlan0. Jan 26 15:49:36 volumiokhv systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Jan 26 15:49:36 volumiokhv systemd[1]: nfs-config.service: Succeeded. Jan 26 15:49:36 volumiokhv systemd[1]: Started Preprocess NFS configuration. Jan 26 15:49:36 volumiokhv systemd[1]: plymouth-read-write.service: Succeeded. Jan 26 15:49:36 volumiokhv systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Jan 26 15:49:36 volumiokhv systemd[1]: Received SIGRTMIN+20 from PID 245 (plymouthd). Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target NFS client services. Jan 26 15:49:36 volumiokhv systemd[1]: Started Create Volatile Files and Directories. Jan 26 15:49:36 volumiokhv systemd[1]: Starting Update UTMP about System Boot/Shutdown... Jan 26 15:49:36 volumiokhv systemd[1]: Starting RPC bind portmap service... Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Jan 26 15:49:36 volumiokhv systemd[1]: Started Update UTMP about System Boot/Shutdown. Jan 26 15:49:36 volumiokhv systemd[1]: Started RPC bind portmap service. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target RPC Port Mapper. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Remote File Systems (Pre). Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Remote File Systems. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target System Initialization. Jan 26 15:49:36 volumiokhv systemd[1]: Listening on triggerhappy.socket. Jan 26 15:49:36 volumiokhv systemd[1]: Listening on D-Bus System Message Bus Socket. Jan 26 15:49:36 volumiokhv systemd[1]: Listening on mpd.socket. Jan 26 15:49:36 volumiokhv systemd[1]: Started Daily Cleanup of Temporary Directories. Jan 26 15:49:36 volumiokhv systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Sockets. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Basic System. Jan 26 15:49:36 volumiokhv systemd[1]: Started UPnP Renderer front-end to MPD. Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Jan 26 15:49:36 volumiokhv systemd[1]: Starting dhcpcd on all interfaces... Jan 26 15:49:36 volumiokhv systemd[1]: Started D-Bus System Message Bus. Jan 26 15:49:36 volumiokhv systemd[1]: Starting WPA supplicant... Jan 26 15:49:36 volumiokhv systemd[1]: Started Volumio Iptables Module. Jan 26 15:49:36 volumiokhv systemd[1]: Starting Configure Bluetooth Modems connected by UART... Jan 26 15:49:36 volumiokhv dhcpcd[426]: Not running dhcpcd because /etc/network/interfaces Jan 26 15:49:36 volumiokhv dhcpcd[426]: defines some interfaces that will use a Jan 26 15:49:36 volumiokhv dhcpcd[426]: DHCP client or static address Jan 26 15:49:36 volumiokhv systemd[1]: Started volumio-remote-updater.service. Jan 26 15:49:36 volumiokhv systemd[1]: Started Manage Sound Card State (restore and store). Jan 26 15:49:36 volumiokhv systemd[1]: Starting Save/Restore Sound Card State... Jan 26 15:49:36 volumiokhv systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Jan 26 15:49:36 volumiokhv alsactl[441]: alsactl 1.1.8 daemon started Jan 26 15:49:36 volumiokhv systemd[1]: Starting Wireless Services... Jan 26 15:49:36 volumiokhv systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Jan 26 15:49:36 volumiokhv systemd[1]: Started Daily apt download activities. Jan 26 15:49:36 volumiokhv systemd[1]: Started Daily apt upgrade and clean activities. Jan 26 15:49:36 volumiokhv systemd[1]: Reached target Timers. Jan 26 15:49:36 volumiokhv systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Jan 26 15:49:36 volumiokhv systemd[1]: Starting triggerhappy global hotkey daemon... Jan 26 15:49:36 volumiokhv systemd[1]: Starting Login Service... Jan 26 15:49:36 volumiokhv systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Jan 26 15:49:36 volumiokhv systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Jan 26 15:49:36 volumiokhv systemd[1]: Failed to start dhcpcd on all interfaces. Jan 26 15:49:36 volumiokhv systemd[1]: Started Save/Restore Sound Card State. Jan 26 15:49:37 volumiokhv systemd[1]: Reached target Sound Card. Jan 26 15:49:37 volumiokhv thd[455]: Unable to parse trigger line: Jan 26 15:49:37 volumiokhv thd[455]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Jan 26 15:49:37 volumiokhv thd[455]: Unable to parse trigger line: Jan 26 15:49:37 volumiokhv thd[455]: Found socket passed from systemd Jan 26 15:49:37 volumiokhv kernel: uart-pl011 fe201000.serial: no DMA platform data Jan 26 15:49:37 volumiokhv kernel: 8021q: 802.1Q VLAN Support v1.8 Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Successfully dropped root privileges. Jan 26 15:49:37 volumiokhv avahi-daemon[448]: avahi-daemon 0.7 starting up. Jan 26 15:49:37 volumiokhv systemd[1]: Started triggerhappy global hotkey daemon. Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Successfully called chroot(). Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Successfully dropped remaining capabilities. Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Loading service file /services/volumio.service. Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Network interface enumeration completed. Jan 26 15:49:37 volumiokhv kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Server startup complete. Host name is volumiokhv.local. Local service cookie is 2440273548. Jan 26 15:49:37 volumiokhv avahi-daemon[448]: Service "VolumioKHV" (/services/volumio.service) successfully established. Jan 26 15:49:37 volumiokhv systemd[1]: Started Avahi mDNS/DNS-SD Stack. Jan 26 15:49:37 volumiokhv systemd-logind[457]: New seat seat0. Jan 26 15:49:37 volumiokhv systemd[1]: Started Login Service. Jan 26 15:49:38 volumiokhv sh[368]: eth0: waiting for carrier Jan 26 15:49:38 volumiokhv kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) Jan 26 15:49:38 volumiokhv kernel: bcmgenet fd580000.ethernet eth0: Link is Down Jan 26 15:49:38 volumiokhv dhcpcd[420]: eth0: waiting for carrier Jan 26 15:49:38 volumiokhv sh[373]: wlan0=wlan0 Jan 26 15:49:38 volumiokhv systemd[1]: Started Raise network interfaces. Jan 26 15:49:38 volumiokhv loadcpufreq[452]: Loading cpufreq kernel modules...done (none). Jan 26 15:49:38 volumiokhv systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Jan 26 15:49:38 volumiokhv systemd[1]: Starting LSB: set CPUFreq kernel parameters... Jan 26 15:49:38 volumiokhv cpufrequtils[560]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Jan 26 15:49:38 volumiokhv systemd[1]: Started LSB: set CPUFreq kernel parameters. Jan 26 15:49:38 volumiokhv volumio-remote-updater[440]: Error: No active session Jan 26 15:49:38 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:38] [info] asio async_connect error: system:111 (Connection refused) Jan 26 15:49:38 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:38] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 26 15:49:38 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:38] [error] handle_connect error: Underlying Transport Error Jan 26 15:49:38 volumiokhv systemd[1]: Started WPA supplicant. Jan 26 15:49:38 volumiokhv systemd[1]: Reached target Network. Jan 26 15:49:38 volumiokhv wpa_supplicant[434]: Successfully initialized wpa_supplicant Jan 26 15:49:38 volumiokhv systemd[1]: Starting Music Player Daemon... Jan 26 15:49:38 volumiokhv systemd[1]: Starting Permit User Sessions... Jan 26 15:49:38 volumiokhv volumio[424]: Could not open config: /tmp/upmpdcli.conf Jan 26 15:49:38 volumiokhv systemd[1]: Starting Network Time Service... Jan 26 15:49:38 volumiokhv systemd[1]: Starting OpenBSD Secure Shell server... Jan 26 15:49:38 volumiokhv systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Jan 26 15:49:38 volumiokhv systemd[1]: Reached target Network is Online. Jan 26 15:49:38 volumiokhv systemd[1]: Starting LSB: Brings up/down network automatically... Jan 26 15:49:38 volumiokhv systemd[1]: Starting /etc/rc.local Compatibility... Jan 26 15:49:38 volumiokhv systemd[1]: Starting Samba NMB Daemon... Jan 26 15:49:38 volumiokhv systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 26 15:49:38 volumiokhv systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 26 15:49:38 volumiokhv systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 26 15:49:38 volumiokhv systemd[1]: Started Permit User Sessions. Jan 26 15:49:38 volumiokhv systemd[1]: Started /etc/rc.local Compatibility. Jan 26 15:49:38 volumiokhv systemd[1]: Starting Hold until boot process finishes up... Jan 26 15:49:38 volumiokhv systemd[1]: Starting Terminate Plymouth Boot Screen... Jan 26 15:49:38 volumiokhv systemd[1]: Received SIGRTMIN+21 from PID 245 (plymouthd). Jan 26 15:49:39 volumiokhv systemd[1]: plymouth-start.service: Succeeded. Jan 26 15:49:39 volumiokhv systemd[1]: plymouth-quit-wait.service: Succeeded. Jan 26 15:49:39 volumiokhv systemd[1]: Started Hold until boot process finishes up. Jan 26 15:49:39 volumiokhv systemd[1]: plymouth-quit.service: Succeeded. Jan 26 15:49:39 volumiokhv systemd[1]: Started Terminate Plymouth Boot Screen. Jan 26 15:49:39 volumiokhv systemd[1]: Received SIGRTMIN+21 from PID 245 (n/a). Jan 26 15:49:39 volumiokhv ntpd[579]: ntpd 4.2.8p12@1.3728-o (1): Starting Jan 26 15:49:39 volumiokhv ntpd[579]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Jan 26 15:49:39 volumiokhv systemd[1]: Started Network Time Service. Jan 26 15:49:39 volumiokhv systemd[1]: Started Getty on tty1. Jan 26 15:49:39 volumiokhv systemd[1]: Reached target Login Prompts. Jan 26 15:49:39 volumiokhv ifplugd(eth0)[612]: ifplugd 0.28 initializing. Jan 26 15:49:39 volumiokhv ifplugd(eth0)[612]: Using interface eth0/E4:5F:01:81:9C:CE with driver (version: 5.10.90-v7l+) Jan 26 15:49:39 volumiokhv ifplugd(eth0)[612]: Using detection mode: SIOCETHTOOL Jan 26 15:49:39 volumiokhv ifplugd(eth0)[612]: Initialization complete, link beat not detected. Jan 26 15:49:39 volumiokhv ntpd[607]: proto: precision = 0.778 usec (-20) Jan 26 15:49:39 volumiokhv ntpd[607]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Jan 26 15:49:39 volumiokhv ntpd[607]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-06-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Jan 26 15:49:39 volumiokhv ntpd[607]: Listen and drop on 0 v6wildcard [::]:123 Jan 26 15:49:39 volumiokhv ntpd[607]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Jan 26 15:49:39 volumiokhv ntpd[607]: Listen normally on 2 lo 127.0.0.1:123 Jan 26 15:49:39 volumiokhv ntpd[607]: Listening on routing socket on fd #19 for interface updates Jan 26 15:49:39 volumiokhv ntpd[607]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 26 15:49:39 volumiokhv ntpd[607]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Jan 26 15:49:39 volumiokhv systemd[1]: iptables.service: Succeeded. Jan 26 15:49:39 volumiokhv ifplugd[585]: Network Interface Plugging Daemon...start eth0...done. Jan 26 15:49:39 volumiokhv systemd[1]: Started LSB: Brings up/down network automatically. Jan 26 15:49:39 volumiokhv haveged[405]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Jan 26 15:49:39 volumiokhv haveged[405]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Jan 26 15:49:39 volumiokhv haveged[405]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 8.00497 Jan 26 15:49:39 volumiokhv haveged[405]: haveged: fills: 0, generated: 0 Jan 26 15:49:39 volumiokhv kernel: random: crng init done Jan 26 15:49:39 volumiokhv kernel: random: 7 urandom warning(s) missed due to ratelimiting Jan 26 15:49:39 volumiokhv sshd[618]: Server listening on 0.0.0.0 port 22. Jan 26 15:49:39 volumiokhv sshd[618]: Server listening on :: port 22. Jan 26 15:49:39 volumiokhv systemd[1]: Started OpenBSD Secure Shell server. Jan 26 15:49:40 volumiokhv ntpd[607]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jan 26 15:49:40 volumiokhv nmbd[593]: [2022/01/26 15:49:40.432519, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Jan 26 15:49:40 volumiokhv nmbd[593]: started asyncdns process 625 Jan 26 15:49:40 volumiokhv nmbd[593]: [2022/01/26 15:49:40.434476, 0] ../lib/util/become_daemon.c:149(daemon_status) Jan 26 15:49:40 volumiokhv nmbd[593]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Jan 26 15:49:40 volumiokhv nmbd[593]: [2022/01/26 15:49:40.434623, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Jan 26 15:49:40 volumiokhv nmbd[593]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Jan 26 15:49:40 volumiokhv wireless.js[447]: WIRELESS DAEMON: start Jan 26 15:49:40 volumiokhv wireless.js[447]: WIRELESS: Loaded configuration Jan 26 15:49:40 volumiokhv wireless.js[447]: Cleaning previous... Jan 26 15:49:40 volumiokhv systemd[1]: systemd-rfkill.service: Succeeded. Jan 26 15:49:41 volumiokhv sudo[629]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 26 15:49:41 volumiokhv sudo[629]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:41 volumiokhv sudo[629]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:41 volumiokhv sudo[631]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 26 15:49:41 volumiokhv sudo[631]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:41 volumiokhv ntpd[607]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jan 26 15:49:41 volumiokhv mpd[613]: Jan 26 15:49 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 15:49:41 volumiokhv sudo[631]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:41 volumiokhv mpd[613]: Jan 26 15:49 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 26 15:49:41 volumiokhv mpd[613]: Jan 26 15:49 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 26 15:49:41 volumiokhv wireless.js[447]: Stopped aP Jan 26 15:49:41 volumiokhv wireless.js[447]: Start wireless flow Jan 26 15:49:41 volumiokhv wireless.js[447]: Stopped hotspot (if there).. Jan 26 15:49:41 volumiokhv systemd[1]: Started Music Player Daemon. Jan 26 15:49:41 volumiokhv sudo[638]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 26 15:49:41 volumiokhv sudo[638]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:41 volumiokhv sudo[638]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:41 volumiokhv sudo[642]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 26 15:49:41 volumiokhv sudo[642]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:41 volumiokhv sudo[642]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:41 volumiokhv wireless.js[447]: DHCP IP Jan 26 15:49:41 volumiokhv wireless.js[447]: Start ap Jan 26 15:49:41 volumiokhv wpa_supplicant[644]: Successfully initialized wpa_supplicant Jan 26 15:49:41 volumiokhv sudo[645]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jan 26 15:49:41 volumiokhv sudo[645]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:41 volumiokhv kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 26 15:49:41 volumiokhv dhcpcd[646]: dev: loaded udev Jan 26 15:49:41 volumiokhv dhcpcd-run-hooks[664]: wlan0: starting wpa_supplicant Jan 26 15:49:42 volumiokhv dhcpcd-run-hooks[669]: wlan0: failed to start wpa_supplicant Jan 26 15:49:42 volumiokhv dhcpcd-run-hooks[670]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Jan 26 15:49:42 volumiokhv dhcpcd[646]: wlan0: connected to Access Point `' Jan 26 15:49:42 volumiokhv ntpd[607]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jan 26 15:49:42 volumiokhv dhcpcd[646]: no interfaces have a carrier Jan 26 15:49:42 volumiokhv dhcpcd[646]: forked to background, child pid 680 Jan 26 15:49:42 volumiokhv dhcpcd[680]: eth0: waiting for carrier Jan 26 15:49:42 volumiokhv dhcpcd[680]: wlan0: waiting for carrier Jan 26 15:49:42 volumiokhv sudo[645]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:42 volumiokhv wireless.js[447]: trying... Jan 26 15:49:42 volumiokhv sudo[682]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:42 volumiokhv sudo[682]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:42 volumiokhv sudo[682]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:43 volumiokhv ntpd[607]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jan 26 15:49:43 volumiokhv wireless.js[447]: trying... Jan 26 15:49:43 volumiokhv sudo[685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:43 volumiokhv sudo[685]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:43 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:43] [info] asio async_connect error: system:111 (Connection refused) Jan 26 15:49:43 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:43] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 26 15:49:43 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:43] [error] handle_connect error: Underlying Transport Error Jan 26 15:49:43 volumiokhv sudo[685]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:44 volumiokhv kernel: Bluetooth: Core ver 2.22 Jan 26 15:49:44 volumiokhv kernel: NET: Registered protocol family 31 Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI device and connection manager initialized Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI socket layer initialized Jan 26 15:49:44 volumiokhv kernel: Bluetooth: L2CAP socket layer initialized Jan 26 15:49:44 volumiokhv kernel: Bluetooth: SCO socket layer initialized Jan 26 15:49:44 volumiokhv btuart[437]: bcm43xx_init Jan 26 15:49:44 volumiokhv btuart[437]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd Jan 26 15:49:44 volumiokhv btuart[437]: Set Controller UART speed to 3000000 bit/s Jan 26 15:49:44 volumiokhv btuart[437]: Device setup complete Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI UART driver ver 2.3 Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI UART protocol H4 registered Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Jan 26 15:49:44 volumiokhv kernel: Bluetooth: HCI UART protocol Broadcom registered Jan 26 15:49:44 volumiokhv systemd[1]: Starting Load/Save RF Kill Switch Status... Jan 26 15:49:44 volumiokhv systemd[1]: Started Configure Bluetooth Modems connected by UART. Jan 26 15:49:44 volumiokhv systemd[1]: Started Load/Save RF Kill Switch Status. Jan 26 15:49:44 volumiokhv systemd[1]: Created slice system-bthelper.slice. Jan 26 15:49:44 volumiokhv systemd[1]: Starting Raspberry Pi bluetooth helper... Jan 26 15:49:44 volumiokhv bthelper[697]: Raspberry Pi BDADDR already set Jan 26 15:49:44 volumiokhv systemd[1]: Started Raspberry Pi bluetooth helper. Jan 26 15:49:44 volumiokhv systemd[1]: Starting Bluetooth service... Jan 26 15:49:44 volumiokhv bluetoothd[707]: Bluetooth daemon 5.50 Jan 26 15:49:44 volumiokhv bluetoothd[707]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Jan 26 15:49:44 volumiokhv systemd[1]: Started Bluetooth service. Jan 26 15:49:44 volumiokhv systemd[1]: Reached target Bluetooth. Jan 26 15:49:44 volumiokhv bluetoothd[707]: Starting SDP server Jan 26 15:49:44 volumiokhv bluetoothd[707]: Excluding (cli) sap Jan 26 15:49:44 volumiokhv kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jan 26 15:49:44 volumiokhv kernel: Bluetooth: BNEP filters: protocol multicast Jan 26 15:49:44 volumiokhv kernel: Bluetooth: BNEP socket layer initialized Jan 26 15:49:44 volumiokhv bluetoothd[707]: Bluetooth management interface 1.18 initialized Jan 26 15:49:44 volumiokhv dbus-daemon[428]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=707 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jan 26 15:49:44 volumiokhv systemd[1]: Starting Hostname Service... Jan 26 15:49:44 volumiokhv dbus-daemon[428]: [system] Successfully activated service 'org.freedesktop.hostname1' Jan 26 15:49:44 volumiokhv systemd[1]: Started Hostname Service. Jan 26 15:49:44 volumiokhv bluetoothd[707]: Failed to set privacy: Rejected (0x0b) Jan 26 15:49:44 volumiokhv wpa_supplicant[668]: wlan0: Trying to associate with SSID 'icanhearyouhavingsex' Jan 26 15:49:44 volumiokhv wireless.js[447]: trying... Jan 26 15:49:44 volumiokhv sudo[711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:44 volumiokhv sudo[711]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:44 volumiokhv sudo[711]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:45 volumiokhv wireless.js[447]: trying... Jan 26 15:49:45 volumiokhv sudo[714]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:45 volumiokhv sudo[714]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:45 volumiokhv sudo[714]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:46 volumiokhv wireless.js[447]: trying... Jan 26 15:49:46 volumiokhv sudo[717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:46 volumiokhv sudo[717]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:46 volumiokhv sudo[717]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: carrier acquired Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: connected to Access Point `icanhearyouhavingsex' Jan 26 15:49:47 volumiokhv wpa_supplicant[668]: wlan0: Associated with 60:e3:27:4f:c2:5d Jan 26 15:49:47 volumiokhv wpa_supplicant[668]: wlan0: CTRL-EVENT-CONNECTED - Connection to 60:e3:27:4f:c2:5d completed [id=0 id_str=] Jan 26 15:49:47 volumiokhv wpa_supplicant[668]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 26 15:49:47 volumiokhv wpa_supplicant[668]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jan 26 15:49:47 volumiokhv dhcpcd[680]: DUID 00:01:00:01:29:78:3f:d3:e4:5f:01:81:9c:ce Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: IAID 01:81:9c:d0 Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: adding address fe80::7bea:5bcc:e2c8:d4d6 Jan 26 15:49:47 volumiokhv dhcpcd[680]: ipv6_addaddr1: Permission denied Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: carrier lost Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: carrier acquired Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: IAID 01:81:9c:d0 Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: soliciting an IPv6 router Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: rebinding lease of 192.168.1.65 Jan 26 15:49:47 volumiokhv dhcpcd[680]: wlan0: probing address 192.168.1.65/24 Jan 26 15:49:47 volumiokhv wireless.js[447]: trying... Jan 26 15:49:47 volumiokhv sudo[732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:47 volumiokhv sudo[732]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:47 volumiokhv sudo[732]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:48 volumiokhv wireless.js[447]: trying... Jan 26 15:49:48 volumiokhv sudo[735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:48 volumiokhv sudo[735]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:48 volumiokhv sudo[735]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:49 volumiokhv systemd[1]: systemd-rfkill.service: Succeeded. Jan 26 15:49:49 volumiokhv bthelper[697]: Changing power off succeeded Jan 26 15:49:49 volumiokhv bthelper[697]: [CHG] Controller E4:5F:01:81:9C:D2 Class: 0x0000041c Jan 26 15:49:49 volumiokhv bthelper[697]: Changing power on succeeded Jan 26 15:49:49 volumiokhv wireless.js[447]: trying... Jan 26 15:49:49 volumiokhv sudo[745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:49 volumiokhv sudo[745]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:49 volumiokhv sudo[745]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:50 volumiokhv wireless.js[447]: trying... Jan 26 15:49:50 volumiokhv sudo[748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:50 volumiokhv sudo[748]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:50 volumiokhv sudo[748]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:51 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:51] [info] asio async_connect error: system:111 (Connection refused) Jan 26 15:49:51 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:51] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 26 15:49:51 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:49:51] [error] handle_connect error: Underlying Transport Error Jan 26 15:49:51 volumiokhv wireless.js[447]: trying... Jan 26 15:49:51 volumiokhv sudo[751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:51 volumiokhv sudo[751]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:51 volumiokhv sudo[751]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:52 volumiokhv wireless.js[447]: trying... Jan 26 15:49:52 volumiokhv sudo[754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:52 volumiokhv sudo[754]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:52 volumiokhv sudo[754]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:53 volumiokhv dhcpcd[680]: wlan0: leased 192.168.1.65 for 43200 seconds Jan 26 15:49:53 volumiokhv avahi-daemon[448]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.65. Jan 26 15:49:53 volumiokhv avahi-daemon[448]: New relevant interface wlan0.IPv4 for mDNS. Jan 26 15:49:53 volumiokhv dhcpcd[680]: wlan0: adding route to 192.168.1.0/24 Jan 26 15:49:53 volumiokhv avahi-daemon[448]: Registering new address record for 192.168.1.65 on wlan0.IPv4. Jan 26 15:49:53 volumiokhv dhcpcd[680]: wlan0: adding default route via 192.168.1.1 Jan 26 15:49:53 volumiokhv wireless.js[447]: trying... Jan 26 15:49:53 volumiokhv sudo[778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 26 15:49:53 volumiokhv sudo[778]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:53 volumiokhv sudo[778]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:53 volumiokhv wireless.js[447]: Connected to: ----icanhearyouhavingsex Jan 26 15:49:53 volumiokhv wireless.js[447]: ---- Jan 26 15:49:53 volumiokhv sudo[781]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 15:49:53 volumiokhv sudo[781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:53 volumiokhv sudo[781]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:53 volumiokhv wireless.js[447]: ... joined AP, wlan0 IPv4 is 192.168.1.65, ipV6 is undefined Jan 26 15:49:53 volumiokhv wireless.js[447]: It's done! AP Jan 26 15:49:53 volumiokhv kernel: cam-dummy-reg: disabling Jan 26 15:49:53 volumiokhv kernel: cam1-reg: disabling Jan 26 15:49:53 volumiokhv systemd[1]: Started Wireless Services. Jan 26 15:49:53 volumiokhv systemd[1]: Started Volumio Backend Module. Jan 26 15:49:53 volumiokhv systemd[1]: Started Volumio Streaming Daemon. Jan 26 15:49:53 volumiokhv volumio-streaming-daemon[786]: ############################ Jan 26 15:49:53 volumiokhv volumio-streaming-daemon[786]: # Volumio Streaming Daemon # Jan 26 15:49:53 volumiokhv volumio-streaming-daemon[786]: # Running on port 7777 # Jan 26 15:49:53 volumiokhv volumio-streaming-daemon[786]: ############################ Jan 26 15:49:53 volumiokhv volumio-streaming-daemon[786]: Environment: production Jan 26 15:49:55 volumiokhv ntpd[607]: Listen normally on 3 wlan0 192.168.1.65:123 Jan 26 15:49:55 volumiokhv ntpd[607]: new interface(s) found: waking up resolver Jan 26 15:49:55 volumiokhv nmbd[593]: [2022/01/26 15:49:55.441734, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 15:49:55 volumiokhv nmbd[593]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 26 15:49:55 volumiokhv systemd[1]: Started Samba NMB Daemon. Jan 26 15:49:55 volumiokhv systemd[1]: Starting Samba Winbind Daemon... Jan 26 15:49:55 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:49:55 volumiokhv volumio[785]: info: ----- Volumio3 ---- Jan 26 15:49:55 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:49:55 volumiokhv volumio[785]: info: ----- System startup ---- Jan 26 15:49:55 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:49:55 volumiokhv winbindd[806]: [2022/01/26 15:49:55.665315, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 26 15:49:55 volumiokhv winbindd[806]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 26 15:49:55 volumiokhv winbindd[806]: [2022/01/26 15:49:55.697817, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 15:49:55 volumiokhv winbindd[806]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 26 15:49:55 volumiokhv systemd[1]: Started Samba Winbind Daemon. Jan 26 15:49:55 volumiokhv systemd[1]: Starting Samba SMB Daemon... Jan 26 15:49:56 volumiokhv systemd[1]: Started Samba SMB Daemon. Jan 26 15:49:56 volumiokhv systemd[1]: Reached target Multi-User System. Jan 26 15:49:56 volumiokhv systemd[1]: Reached target Graphical Interface. Jan 26 15:49:56 volumiokhv systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 26 15:49:56 volumiokhv smbd[811]: [2022/01/26 15:49:56.137577, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 26 15:49:56 volumiokhv smbd[811]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 26 15:49:56 volumiokhv systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 26 15:49:56 volumiokhv systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 26 15:49:56 volumiokhv systemd[1]: Startup finished in 9.588s (kernel) + 25.921s (userspace) = 35.510s. Jan 26 15:49:56 volumiokhv volumio[785]: info: MYVOLUMIO Environment detected Jan 26 15:49:56 volumiokhv volumio[785]: info: Plugin folders cleanup Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning into folder /volumio/app/plugins/ Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category audio_interface Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category miscellanea Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category music_service Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category plugins.json Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category system_controller Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category user_interface Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning into folder /data/plugins/ Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category music_service Jan 26 15:49:56 volumiokhv volumio[785]: info: Scanning category user_interface Jan 26 15:49:56 volumiokhv volumio[785]: info: Plugin folders cleanup completed Jan 26 15:49:56 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:49:56 volumiokhv volumio[785]: info: ----- Core plugins startup ---- Jan 26 15:49:56 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:49:56 volumiokhv volumio[785]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 15:49:56 volumiokhv volumio[785]: info: Adding plugin upnp to MyMusic Plugins Jan 26 15:49:56 volumiokhv volumio[785]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 15:49:56 volumiokhv volumio[785]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 15:49:56 volumiokhv volumio[785]: info: Loading plugins from folder /data/plugins/ Jan 26 15:49:56 volumiokhv volumio[785]: info: Loading plugin "system"... Jan 26 15:49:56 volumiokhv volumio[785]: info: Loading plugin "appearance"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "network"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Refreshing Cached IP Addresses Jan 26 15:49:57 volumiokhv sudo[823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 15:49:57 volumiokhv sudo[823]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:57 volumiokhv sudo[823]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:57 volumiokhv sudo[825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 15:49:57 volumiokhv sudo[825]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:57 volumiokhv sudo[825]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "services"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "alsa_controller"... Jan 26 15:49:57 volumiokhv sudo[829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 15:49:57 volumiokhv sudo[829]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "wizard"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "volumio_command_line_client"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "upnp"... Jan 26 15:49:57 volumiokhv volumio[785]: info: [1643212197685] Starting Upmpd Daemon Jan 26 15:49:57 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "my_music"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Loading plugin "mpd"... Jan 26 15:49:57 volumiokhv volumio[785]: info: Creating MPD Configuration file Jan 26 15:49:58 volumiokhv volumio[785]: info: Plugin upnp_browser is not enabled Jan 26 15:49:58 volumiokhv volumio[785]: info: Loading plugin "networkfs"... Jan 26 15:49:58 volumiokhv sudo[834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 15:49:58 volumiokhv sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:58 volumiokhv sudo[834]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:58 volumiokhv sudo[836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 15:49:58 volumiokhv sudo[836]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:58 volumiokhv systemd[1]: Stopping Music Player Daemon... Jan 26 15:49:58 volumiokhv systemd[1]: mpd.service: Succeeded. Jan 26 15:49:58 volumiokhv systemd[1]: Stopped Music Player Daemon. Jan 26 15:49:58 volumiokhv systemd[1]: Starting Music Player Daemon... Jan 26 15:49:58 volumiokhv sudo[844]: 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.1.15/musicshare /mnt/NAS/Musik Jan 26 15:49:58 volumiokhv sudo[844]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:58 volumiokhv volumio[785]: info: Starting Udev Watcher for removable devices Jan 26 15:49:58 volumiokhv sudo[846]: 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.1.15/musicshare_hires /mnt/NAS/Musik_Hi-Res Jan 26 15:49:58 volumiokhv sudo[846]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:58 volumiokhv sudo[851]: 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.1.15/musicshare_new /mnt/NAS/Musik_Neu Jan 26 15:49:58 volumiokhv sudo[851]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:49:58 volumiokhv kernel: FS-Cache: Netfs 'cifs' registered for caching Jan 26 15:49:58 volumiokhv kernel: Key type cifs.spnego registered Jan 26 15:49:58 volumiokhv kernel: Key type cifs.idmap registered Jan 26 15:49:58 volumiokhv kernel: CIFS: Attempting to mount //192.168.1.15/musicshare Jan 26 15:49:58 volumiokhv kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 26 15:49:58 volumiokhv kernel: CIFS: Attempting to mount //192.168.1.15/musicshare_hires Jan 26 15:49:58 volumiokhv kernel: CIFS: Attempting to mount //192.168.1.15/musicshare_new Jan 26 15:49:58 volumiokhv kernel: FS-Cache: Duplicate cookie detected Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-cookie c=9be43892 [p=edd39931 fl=222 nc=0 na=1] Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-cookie d=3d563bdd n=e79f0bce Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-key=[8] '020001bdc0a8010f' Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-cookie c=2d42a8c1 [p=edd39931 fl=2 nc=0 na=1] Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-cookie d=3d563bdd n=7f848417 Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-key=[8] '020001bdc0a8010f' Jan 26 15:49:58 volumiokhv kernel: FS-Cache: Duplicate cookie detected Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-cookie c=9be43892 [p=edd39931 fl=222 nc=0 na=1] Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-cookie d=3d563bdd n=e79f0bce Jan 26 15:49:58 volumiokhv kernel: FS-Cache: O-key=[8] '020001bdc0a8010f' Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-cookie c=3ef57537 [p=edd39931 fl=2 nc=0 na=1] Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-cookie d=3d563bdd n=3a0cfd77 Jan 26 15:49:58 volumiokhv kernel: FS-Cache: N-key=[8] '020001bdc0a8010f' Jan 26 15:49:58 volumiokhv volumio[785]: info: Ignoring mount for partition: boot Jan 26 15:49:58 volumiokhv volumio[785]: info: Ignoring mount for partition: volumio Jan 26 15:49:58 volumiokhv volumio[785]: info: Ignoring mount for partition: volumio_data Jan 26 15:49:58 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:49:58 volumiokhv volumio[785]: info: Loading plugin "alarm-clock"... Jan 26 15:49:58 volumiokhv volumio[785]: info: Plugin airplay_emulation is not enabled Jan 26 15:49:58 volumiokhv volumio[785]: info: Loading plugin "last_100"... Jan 26 15:49:58 volumiokhv volumio[785]: info: Loading plugin "webradio"... Jan 26 15:49:58 volumiokhv mpd[841]: Jan 26 15:49 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 15:49:58 volumiokhv sudo[844]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:58 volumiokhv sudo[846]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:58 volumiokhv sudo[851]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "i2s_dacs"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "volumiodiscovery"... Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** For more information see Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:49:59 volumiokhv volumio[785]: *** WARNING *** For more information see Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** For more information see Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 15:49:59 volumiokhv node[785]: *** WARNING *** For more information see Jan 26 15:49:59 volumiokhv volumio[785]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 15:49:59 volumiokhv volumio[785]: info: Discovery: Started advertising with name: VolumioKHV Jan 26 15:49:59 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "outputs"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "albumart"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Plugin example_plugin is not enabled Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "inputs"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "updater_comm"... Jan 26 15:49:59 volumiokhv mpd[841]: Jan 26 15:49 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 26 15:49:59 volumiokhv mpd[841]: Jan 26 15:49 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 26 15:49:59 volumiokhv systemd[1]: Started Music Player Daemon. Jan 26 15:49:59 volumiokhv sudo[836]: pam_unix(sudo:session): session closed for user root Jan 26 15:49:59 volumiokhv volumio[785]: info: Plugin mpdemulation is not enabled Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "rest_api"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "websocket"... Jan 26 15:49:59 volumiokhv volumio[785]: info: Loading plugin "spop"... Jan 26 15:49:59 volumiokhv volumio[785]: Forking 3 albumart workers Jan 26 15:49:59 volumiokhv volumio[785]: Starting albumart workers Jan 26 15:49:59 volumiokhv volumio[785]: Starting albumart workers Jan 26 15:50:00 volumiokhv volumio[785]: Starting albumart workers Jan 26 15:50:00 volumiokhv volumio[785]: info: Loading plugin "volspotconnect2"... Jan 26 15:50:00 volumiokhv volumio[785]: info: Loading plugin "Systeminfo"... Jan 26 15:50:01 volumiokhv volumio[785]: info: Loading plugin "rotaryencoder2"... Jan 26 15:50:01 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:50:01] [connect] Successful connection Jan 26 15:50:01 volumiokhv volumio[785]: info: Loading i18n strings for locale en Jan 26 15:50:01 volumiokhv volumio[785]: Updating browse sources language Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::initPlayerControls Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: Express server listening on port 3000 Jan 26 15:50:01 volumiokhv volumio[785]: [Metrics] WebUI: 6s 583.52ms Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::resetVolumioState Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::getcurrentVolume Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:50:01 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:50:01 volumiokhv volumio[785]: info: MPD Permissions set Jan 26 15:50:01 volumiokhv volumio[785]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.175 Safari/537.36 Total Clients: 1 Jan 26 15:50:01 volumiokhv volumio[785]: verbose: New Socket.io Connection to 192.168.1.65:3000 from 192.168.1.70 UA: node-XMLHttpRequest Total Clients: 2 Jan 26 15:50:01 volumiokhv volumio-remote-updater[440]: [2022-01-26 15:50:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1643212201 101 Jan 26 15:50:01 volumiokhv volumio[785]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3 Jan 26 15:50:01 volumiokhv volumio[785]: info: MPD running with PID841 Jan 26 15:50:01 volumiokhv volumio[785]: ,establishing connection Jan 26 15:50:01 volumiokhv sudo[829]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: Reloading queue from file Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: Executing start script for DAC IQaudIO DAC Plus Jan 26 15:50:01 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:50:01 volumiokhv volumio[785]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::setRepeat null single undefined Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:50:01 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::setRandom null Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:50:01 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:50:01 volumiokhv volumio[785]: info: Setting Device type: Raspberry PI Jan 26 15:50:01 volumiokhv volumio[785]: info: DAC script executed Jan 26 15:50:01 volumiokhv volumio[785]: info: Completed loading Core Plugins Jan 26 15:50:01 volumiokhv volumio[785]: info: Preparing to generate the ALSA configuration file Jan 26 15:50:01 volumiokhv volumio[785]: info: Discovery: adding f901cb98-0af3-4b36-8034-88ada5fa2b0d Jan 26 15:50:01 volumiokhv volumio[785]: info: mDNS: Found device VolumioKHV Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:01 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:01 volumiokhv volumio[785]: info: Discovery: adding 416f3b7a-e925-46a2-89a7-a1fa7a327840 Jan 26 15:50:01 volumiokhv volumio[785]: info: mDNS: Found device VolumioKHVPI2 Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jan 26 15:50:01 volumiokhv volumio[785]: info: Asound.conf file unchanged, so no further update is needed Jan 26 15:50:01 volumiokhv volumio[785]: info: Output device has changed, restarting MPD Jan 26 15:50:01 volumiokhv sudo[972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 15:50:01 volumiokhv sudo[972]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:01 volumiokhv volumio[785]: info: ___________ START PLUGINS ___________ Jan 26 15:50:01 volumiokhv sudo[972]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:50:01 volumiokhv volumio[785]: info: [1643212201938] CoreMusicLibrary::Adding element Last_100 Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:01 volumiokhv sudo[974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 15:50:01 volumiokhv sudo[974]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:50:01 volumiokhv volumio[785]: info: [1643212201945] CoreMusicLibrary::Adding element Webradio Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 15:50:01 volumiokhv systemd[1]: Stopping Music Player Daemon... Jan 26 15:50:01 volumiokhv volumio[785]: [SpotifyConnect] Creating VLS config file Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:01 volumiokhv volumio[785]: [SpotifyConnect] <> or Mixer found, using softvol Jan 26 15:50:01 volumiokhv volumio[785]: [SpotifyConnect] Starting metadata listener Jan 26 15:50:01 volumiokhv sudo[978]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start spop.service Jan 26 15:50:01 volumiokhv sudo[978]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:01 volumiokhv systemd[1]: mpd.service: Succeeded. Jan 26 15:50:01 volumiokhv systemd[1]: Stopped Music Player Daemon. Jan 26 15:50:02 volumiokhv systemd[1]: Starting Music Player Daemon... Jan 26 15:50:02 volumiokhv systemd[1]: Configuration file /lib/systemd/system/spop.service is marked executable. Please remove executable permission bits. Proceeding anyway. Jan 26 15:50:02 volumiokhv systemd[1]: Configuration file /lib/systemd/system/spop.service is marked world-writable. Please remove world writability permission bits. Proceeding anyway. Jan 26 15:50:02 volumiokhv systemd[1]: Started Spotify Daemon. Jan 26 15:50:02 volumiokhv sudo[978]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:02 volumiokhv sudo[982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Jan 26 15:50:02 volumiokhv sudo[982]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:02 volumiokhv volumio[785]: info: Volumio Calling Home Jan 26 15:50:02 volumiokhv systemd[1]: Started Volspotconnect2 Daemon. Jan 26 15:50:02 volumiokhv sudo[982]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:02 volumiokhv sudo[992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=5 pin_b=6 relative_axis=true steps-per-period=1 Jan 26 15:50:02 volumiokhv sudo[992]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:02 volumiokhv volumio[983]: 2022-01-26 15:50:02 [SPTF] 15:50:02.173 I [offline_authorizer.cpp:297] Unable to login offline: no such user Jan 26 15:50:02 volumiokhv volumio[983]: 2022-01-26 15:50:02 [SPTF] 15:50:02.174 I [ap:1752] Connecting to AP ap.spotify.com:4070 Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:02 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:02 volumiokhv volumio[987]: vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04 Jan 26 15:50:02 volumiokhv volumio[987]: Reading Config from "volspotify.toml" Jan 26 15:50:02 volumiokhv volumio[785]: error: MPD error: Error: write EPIPE Jan 26 15:50:02 volumiokhv volumio[785]: [SpotifyConnect] Vollibrespot Daemon service started! Jan 26 15:50:02 volumiokhv volumio[785]: [Metrics] SpotifyConnect: 0s 242.79ms Jan 26 15:50:02 volumiokhv volumio[785]: info: SpopD Daemon Started Jan 26 15:50:02 volumiokhv volumio[785]: info: MPD Permissions set Jan 26 15:50:02 volumiokhv volumio[987]: [Vollibrespot] : Using Alsa backend with device: volumio Jan 26 15:50:02 volumiokhv volumio[983]: 2022-01-26 15:50:02 [SPTF] 15:50:02.228 I [ap:1226] Connected to AP: 104.199.65.135:4070 Jan 26 15:50:02 volumiokhv volumio[785]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Jan 26 15:50:02 volumiokhv volumio[785]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:02 volumiokhv volumio[987]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Jan 26 15:50:02 volumiokhv kernel: rotary-encoder rotary@5: gray Jan 26 15:50:02 volumiokhv kernel: input: rotary@5 as /devices/platform/rotary@5/input/input0 Jan 26 15:50:02 volumiokhv sudo[992]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:02 volumiokhv volumio[785]: info: Volumio called home Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:02 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:02 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:02 volumiokhv systemd-udevd[1012]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 26 15:50:02 volumiokhv mpd[996]: Jan 26 15:50 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 15:50:02 volumiokhv mpd[996]: Jan 26 15:50 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jan 26 15:50:02 volumiokhv mpd[996]: Jan 26 15:50 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jan 26 15:50:02 volumiokhv systemd[1]: Started Music Player Daemon. Jan 26 15:50:02 volumiokhv sudo[974]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:02 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:50:03 volumiokhv volumio[983]: 2022-01-26 15:50:03 [SPTF] 15:50:03.524 I [offline-mgr:2030] 0 files are locked. 0 images are locked Jan 26 15:50:03 volumiokhv volumio[983]: 2022-01-26 15:50:03 [SPTF] 15:50:03.524 I [offline-mgr:2056] 0 files unlocked. 0 images unlocked Jan 26 15:50:04 volumiokhv volumio[785]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.175 Safari/537.36 Total Clients: 6 Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetVisibleSources Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:04 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 26 15:50:04 volumiokhv volumio[785]: info: Listing playlists Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetQueue Jan 26 15:50:04 volumiokhv volumio[785]: info: CoreStateMachine::getQueue Jan 26 15:50:04 volumiokhv volumio[785]: info: CorePlayQueue::getQueue Jan 26 15:50:06 volumiokhv systemd[1]: systemd-fsckd.service: Succeeded. Jan 26 15:50:07 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:50:07 volumiokhv volumio[785]: info: Connecting to daemon Jan 26 15:50:07 volumiokhv volumio[785]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:50:07 volumiokhv volumio[785]: info: [1643212207236] CoreMusicLibrary::Adding element Spotify Jan 26 15:50:07 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:07 volumiokhv volumio[785]: Cannot find translation for sourceSpotify Jan 26 15:50:07 volumiokhv volumio[785]: info: Completed starting Core Plugins Jan 26 15:50:07 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:50:07 volumiokhv volumio[785]: info: ----- MyVolumio plugins startup ---- Jan 26 15:50:07 volumiokhv volumio[785]: info: ------------------------------------------- Jan 26 15:50:07 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 15:50:07 volumiokhv volumio[785]: info: FIRST BRANCH Jan 26 15:50:07 volumiokhv volumio[785]: info: An error occurred while listing Spotify new albums WebapiError: Unauthorized Jan 26 15:50:07 volumiokhv volumio[785]: info: An error occurred while listing Spotify categories WebapiError: Unauthorized Jan 26 15:50:07 volumiokhv volumio[785]: info: An error occurred while listing Spotify featured playlists WebapiError: Unauthorized Jan 26 15:50:07 volumiokhv sudo[1027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 15:50:07 volumiokhv sudo[1027]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:07 volumiokhv sudo[1027]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:07 volumiokhv sudo[1029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 15:50:07 volumiokhv sudo[1029]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:07 volumiokhv sudo[1029]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:07 volumiokhv sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 15:50:07 volumiokhv sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:07 volumiokhv systemd[1]: Started UPnP Renderer front-end to MPD. Jan 26 15:50:07 volumiokhv sudo[1033]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:07 volumiokhv volumio[785]: info: Upmpdcli Daemon Started Jan 26 15:50:07 volumiokhv volumio[785]: info: New Spotify access token = BQAmKsbpQFXYGEHSDtlSTrBkn56fWFjXbCEkVjyCw2z1D547-YFbWGGmZ3o55rAtS3ikYH9Of8lkclDCgFQ8wDyeoMqh5HcCrDMhqBIpYz1YkAykgsQVqGdGCHLk2OTzUlZL1seurirxgHOUre884aByse9lvPA-K9_k--iiyJFd6-QCAjmjjC8E-EZcx4352g50CrLSwx_UpyRmDx8m Jan 26 15:50:07 volumiokhv volumio[785]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 15:50:07 volumiokhv volumio[1035]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 26 15:50:08 volumiokhv sh[368]: timed out Jan 26 15:50:08 volumiokhv dhcpcd[420]: timed out Jan 26 15:50:08 volumiokhv sh[368]: dhcpcd exited Jan 26 15:50:08 volumiokhv dhcpcd[420]: dhcpcd exited Jan 26 15:50:08 volumiokhv sh[368]: ifup: failed to bring up eth0 Jan 26 15:50:08 volumiokhv systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 26 15:50:08 volumiokhv systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 26 15:50:11 volumiokhv volumio[1035]: .........................................++++ Jan 26 15:50:14 volumiokhv systemd[1]: systemd-hostnamed.service: Succeeded. Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 15:50:15 volumiokhv volumio[785]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 15:50:15 volumiokhv volumio[785]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 15:50:15 volumiokhv volumio[785]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 15:50:15 volumiokhv volumio[785]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 15:50:15 volumiokhv volumio[785]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 15:50:15 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 15:50:15 volumiokhv volumio[1035]: ...........................................++++ Jan 26 15:50:15 volumiokhv volumio[1035]: e is 65537 (0x010001) Jan 26 15:50:15 volumiokhv volumio[1035]: writing RSA key Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 15:50:16 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:16 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:16 volumiokhv volumio[785]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 15:50:16 volumiokhv volumio[785]: info: MyVolumio login type: Token Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 15:50:16 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 15:50:16 volumiokhv volumio[785]: info: Streaming services startup Jan 26 15:50:16 volumiokhv volumio[785]: info: Starting Streaming Daemon Jan 26 15:50:16 volumiokhv sudo[1067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 15:50:16 volumiokhv sudo[1067]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:16 volumiokhv systemd[1]: Stopping Volumio Streaming Daemon... Jan 26 15:50:16 volumiokhv systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM Jan 26 15:50:16 volumiokhv systemd[1]: volumio-streaming-daemon.service: Succeeded. Jan 26 15:50:16 volumiokhv systemd[1]: Stopped Volumio Streaming Daemon. Jan 26 15:50:16 volumiokhv systemd[1]: Started Volumio Streaming Daemon. Jan 26 15:50:16 volumiokhv sudo[1067]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:16 volumiokhv volumio-streaming-daemon[1073]: ############################ Jan 26 15:50:16 volumiokhv volumio-streaming-daemon[1073]: # Volumio Streaming Daemon # Jan 26 15:50:16 volumiokhv volumio-streaming-daemon[1073]: # Running on port 7777 # Jan 26 15:50:16 volumiokhv volumio-streaming-daemon[1073]: ############################ Jan 26 15:50:16 volumiokhv volumio-streaming-daemon[1073]: Environment: production Jan 26 15:50:17 volumiokhv volumio[785]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 15:50:17 volumiokhv volumio[785]: info: MYVOLUMIO: Adding device Jan 26 15:50:17 volumiokhv volumio[785]: info: MYVOLUMIO: Evaluating Server Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Subscribed plan changed to virtuoso Jan 26 15:50:18 volumiokhv volumio[785]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 15:50:18 volumiokhv volumio[785]: info: Removing audio output: Jan 26 15:50:18 volumiokhv volumio[785]: info: MYVOLUMIO: Adding device Jan 26 15:50:18 volumiokhv volumio[785]: info: MYVOLUMIO: Evaluating Server Jan 26 15:50:18 volumiokhv volumio[785]: info: Remote config written successfully Jan 26 15:50:18 volumiokhv volumio[785]: info: Starting Tunnel 1 Jan 26 15:50:18 volumiokhv volumio[785]: info: Starting Tunnel Connection Checker Jan 26 15:50:18 volumiokhv volumio[785]: info: Completed starting MyVolumio Plugin Jan 26 15:50:18 volumiokhv sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 26 15:50:18 volumiokhv sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:50:18 volumiokhv systemd[1]: Started MyVolumio SSH Tunnel. Jan 26 15:50:18 volumiokhv sudo[1093]: pam_unix(sudo:session): session closed for user root Jan 26 15:50:18 volumiokhv volumio[785]: info: Remote SSH Started Jan 26 15:50:18 volumiokhv autossh[1096]: port set to 0, monitoring disabled Jan 26 15:50:18 volumiokhv autossh[1096]: starting ssh (count 1) Jan 26 15:50:18 volumiokhv autossh[1096]: ssh child pid is 1099 Jan 26 15:50:18 volumiokhv volumiossh-tunnel[1095]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[188.166.162.121]:2222' (RSA) to the list of known hosts. Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jan 26 15:50:18 volumiokhv volumio[785]: info: MyVolumio status changed Jan 26 15:50:18 volumiokhv volumio[785]: info: Streaming services startup Jan 26 15:50:18 volumiokhv volumio[785]: info: Re-Starting Streaming Daemon Jan 26 15:50:18 volumiokhv volumio-streaming-daemon[1073]: Restarting daemon Jan 26 15:50:18 volumiokhv volumio-streaming-daemon[1073]: Environment: production Jan 26 15:50:18 volumiokhv volumio[785]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jan 26 15:50:18 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Jan 26 15:50:18 volumiokhv volumio[785]: info: [1643212218650] Starting BluetoothController Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Jan 26 15:50:18 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Jan 26 15:50:18 volumiokhv volumio-streaming-daemon[1073]: Enabled services: Jan 26 15:50:18 volumiokhv volumio-streaming-daemon[1073]: 1) tidal Jan 26 15:50:18 volumiokhv volumio-streaming-daemon[1073]: 2) qobuz Jan 26 15:50:18 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:50:18 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:19 volumiokhv volumio-streaming-daemon[1073]: Environment: production Jan 26 15:50:19 volumiokhv volumio[785]: info: Setting Geolocation for MyVolumio to eu4 Jan 26 15:50:19 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:19 volumiokhv volumio[785]: Current plan: virtuoso. Enabling manifest UI Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Jan 26 15:50:19 volumiokhv volumio[785]: info: Refreshing QOBUZ token Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Jan 26 15:50:19 volumiokhv volumio[785]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Jan 26 15:50:19 volumiokhv volumio[785]: info: Stopping AccessToken refresher cron Jan 26 15:50:19 volumiokhv volumio[785]: info: AccessToken refresher cron started Jan 26 15:50:19 volumiokhv volumio[785]: info: Setting Geolocation for MyVolumio to eu4 Jan 26 15:50:19 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:19 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:19 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:19 volumiokhv volumio[785]: info: Fetching Streaming Services browse cache Jan 26 15:50:19 volumiokhv volumio-streaming-daemon[1073]: Environment: production Jan 26 15:50:19 volumiokhv volumio-streaming-daemon[1073]: Environment: production Jan 26 15:50:19 volumiokhv volumio[785]: info: Fetching Streaming Services browse cache Jan 26 15:50:20 volumiokhv volumio[785]: info: Updating MyVolumio device info Jan 26 15:50:20 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:20 volumiokhv volumio[785]: info: Updating MyVolumio device info Jan 26 15:50:20 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:20 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:21 volumiokhv volumio[785]: info: Access Token successfully retrieved Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 15:50:21 volumiokhv volumio[785]: info: [1643212221121] CoreMusicLibrary::Adding element QOBUZ Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 15:50:21 volumiokhv volumio[785]: Cannot find translation for sourceSpotify Jan 26 15:50:21 volumiokhv volumio[785]: Cannot find translation for sourceQOBUZ Jan 26 15:50:21 volumiokhv volumio[785]: info: Stopping AccessToken refresher cron for QOBUZ Jan 26 15:50:21 volumiokhv volumio[785]: info: AccessToken refresher cron started for QOBUZ Jan 26 15:50:21 volumiokhv volumio[785]: info: BOOT COMPLETED Jan 26 15:50:21 volumiokhv volumio[785]: [Metrics] CommandRouter: 25s 562.15ms Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::volumiosetStartupVolume Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 15:50:21 volumiokhv volumio[785]: info: VolumeController:: Setting startup Volume 30 Jan 26 15:50:21 volumiokhv volumio[785]: info: VolumeController::SetAlsaVolume30 Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::Close All Modals sent Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::Close All Modals sent Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:50:21 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:50:21 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:50:22 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 26 15:50:22 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 26 15:50:22 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 26 15:50:31 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 15:50:31 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 15:50:44 volumiokhv ntpd[607]: Soliciting pool server 212.186.223.161 Jan 26 15:50:45 volumiokhv ntpd[607]: Soliciting pool server 91.206.8.36 Jan 26 15:50:46 volumiokhv ntpd[607]: Soliciting pool server 86.59.80.170 Jan 26 15:50:46 volumiokhv ntpd[607]: Soliciting pool server 212.69.186.39 Jan 26 15:50:47 volumiokhv ntpd[607]: Soliciting pool server 141.255.175.253 Jan 26 15:50:47 volumiokhv ntpd[607]: Soliciting pool server 94.199.173.123 Jan 26 15:50:47 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 26 15:50:48 volumiokhv ntpd[607]: Soliciting pool server 144.76.197.108 Jan 26 15:50:48 volumiokhv volumio[785]: info: handleBrowseUri took 1640 milliseconds Jan 26 15:50:49 volumiokhv ntpd[607]: Soliciting pool server 78.41.116.113 Jan 26 15:50:49 volumiokhv ntpd[607]: Soliciting pool server 217.196.145.42 Jan 26 15:50:50 volumiokhv ntpd[607]: Soliciting pool server 91.206.8.70 Jan 26 15:50:50 volumiokhv ntpd[607]: Soliciting pool server 151.236.30.71 Jan 26 15:50:51 volumiokhv ntpd[607]: Soliciting pool server 178.251.64.52 Jan 26 15:50:51 volumiokhv ntpd[607]: Soliciting pool server 86.59.113.124 Jan 26 15:50:51 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 26 15:50:52 volumiokhv ntpd[607]: Soliciting pool server 185.144.161.170 Jan 26 15:50:52 volumiokhv ntpd[607]: Soliciting pool server 83.137.41.14 Jan 26 15:51:15 volumiokhv ntpd[607]: receive: Unexpected origin timestamp 0xe59bec5c.11f1a148 does not match aorg 0000000000.00000000 from server@78.41.116.113 xmt 0xe59bec73.25c3e7c8 Jan 26 15:51:15 volumiokhv ntpd[607]: receive: Unexpected origin timestamp 0xe59bec5c.11f75445 does not match aorg 0000000000.00000000 from server@86.59.80.170 xmt 0xe59bec73.26f81be0 Jan 26 15:51:15 volumiokhv ntpd[607]: receive: Unexpected origin timestamp 0xe59bec5c.11f597e4 does not match aorg 0000000000.00000000 from server@141.255.175.253 xmt 0xe59bec73.26efb2f4 Jan 26 15:51:15 volumiokhv ntpd[607]: receive: Unexpected origin timestamp 0xe59bec5c.11fa0b73 does not match aorg 0000000000.00000000 from server@212.186.223.161 xmt 0xe59bec73.2778ee3a Jan 26 15:51:16 volumiokhv ntpd[607]: Soliciting pool server 80.92.126.65 Jan 26 15:51:16 volumiokhv ntpd[607]: Soliciting pool server 2a02:1748:0:1500:3::2005 Jan 26 15:51:17 volumiokhv volumio[785]: info: handleBrowseUri took 26270 milliseconds Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreStateMachine::ClearQueue Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreStateMachine::stop Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:51:25 volumiokhv volumio[785]: verbose: UNSET VOLATILE Jan 26 15:51:25 volumiokhv volumio[785]: info: CorePlayQueue::clearPlayQueue Jan 26 15:51:25 volumiokhv volumio[785]: info: CorePlayQueue::saveQueue Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushQueue Jan 26 15:51:25 volumiokhv volumio[785]: info: CoreStateMachine::addQueueItems Jan 26 15:51:25 volumiokhv volumio[785]: info: CorePlayQueue::addQueueItems Jan 26 15:51:25 volumiokhv volumio[785]: info: Adding Item to queue: qobuz://album/d8ke96l5s9qqa Jan 26 15:51:25 volumiokhv volumio[785]: info: Exploding uri qobuz://album/d8ke96l5s9qqa in service qobuz Jan 26 15:51:27 volumiokhv volumio[785]: info: explodeUri took 1819 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: info: CorePlayQueue::saveQueue Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushQueue Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::updateTrackBlock Jan 26 15:51:27 volumiokhv volumio[785]: info: CorePlayQueue::getTrackBlock Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPlay Jan 26 15:51:27 volumiokhv volumio[785]: verbose: UNSET VOLATILE Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::play index 0 Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::stop Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:51:27 volumiokhv volumio[785]: verbose: UNSET VOLATILE Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::play index undefined Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:51:27 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::startPlaybackTimer Jan 26 15:51:27 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:27 volumiokhv volumio[785]: info: [1643212287200] ControllerQobuz::clearAddPlayTrack Jan 26 15:51:27 volumiokhv volumio[785]: info: getStreamUrl took 530 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 15:51:27 volumiokhv volumio[785]: info: sendMpdCommand stop took 1 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand clear Jan 26 15:51:27 volumiokhv volumio[785]: info: Jan 26 15:51:27 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:51:27 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:51:27 volumiokhv volumio[785]: info: sendMpdCommand clear took 3 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand load "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ" Jan 26 15:51:27 volumiokhv volumio[785]: info: Jan 26 15:51:27 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:51:27 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:51:27 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:51:27 volumiokhv volumio[785]: info: ------------------------------ 7ms Jan 26 15:51:27 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ" Jan 26 15:51:27 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:51:27 volumiokhv volumio[785]: info: Jan 26 15:51:27 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:51:27 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:51:27 volumiokhv volumio[785]: info: ------------------------------ 209ms Jan 26 15:51:27 volumiokhv volumio[785]: info: sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ" took 3 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 26 15:51:27 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand play Jan 26 15:51:27 volumiokhv volumio[785]: info: Jan 26 15:51:27 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:51:27 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:51:27 volumiokhv volumio[785]: info: ------------------------------ 8ms Jan 26 15:51:27 volumiokhv volumio[785]: info: sendMpdCommand play took 5 milliseconds Jan 26 15:51:27 volumiokhv volumio[785]: info: ------------------------------ 5ms Jan 26 15:51:28 volumiokhv volumio[785]: info: Jan 26 15:51:28 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:51:28 volumiokhv volumio[785]: info: Jan 26 15:51:28 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand status took 10 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:51:28 volumiokhv volumio[785]: info: Jan 26 15:51:28 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand status took 15 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:28 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","trackType":"qobuz"} Jan 26 15:51:28 volumiokhv volumio[785]: verbose: CURRENT POSITION 0 Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus stop Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: ------------------------------ 40ms Jan 26 15:51:28 volumiokhv volumio[785]: info: Jan 26 15:51:28 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand status took 25 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 23 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand status took 3 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:28 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","trackType":"qobuz"} Jan 26 15:51:28 volumiokhv volumio[785]: verbose: CURRENT POSITION 0 Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:51:28 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: ------------------------------ 70ms Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 48 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 47 milliseconds Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:51:28 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:28 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","trackType":"qobuz"} Jan 26 15:51:28 volumiokhv volumio[785]: verbose: CURRENT POSITION 0 Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:51:28 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:51:28 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202424&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643215887&hmac=qx4CcM4XwcwnXKcV3R6xRofrAkQ","trackType":"qobuz"} Jan 26 15:51:28 volumiokhv volumio[785]: verbose: CURRENT POSITION 0 Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:51:28 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:51:28 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:51:28 volumiokhv volumio[785]: info: ------------------------------ 118ms Jan 26 15:51:28 volumiokhv volumio[785]: info: ------------------------------ 94ms Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioNext Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::next Jan 26 15:54:25 volumiokhv volumio[785]: info: [1643212465401] ControllerQobuz::next Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::next Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::stop Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:54:25 volumiokhv volumio[785]: verbose: UNSET VOLATILE Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::stPlaybackTimer Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::updateTrackBlock Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrackBlock Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::serviceStop Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 0 Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::serviceStop Jan 26 15:54:25 volumiokhv volumio[785]: info: [1643212465409] ControllerQobuz::stop Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 26 15:54:25 volumiokhv volumio[785]: info: ControllerMpd::stop Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 15:54:25 volumiokhv volumio[785]: info: sendMpdCommand stop took 84 milliseconds Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::play index undefined Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::startPlaybackTimer Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: [1643212465496] ControllerQobuz::clearAddPlayTrack Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::updateTrackBlock Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrackBlock Jan 26 15:54:25 volumiokhv volumio[785]: info: Jan 26 15:54:25 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:25 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:25 volumiokhv volumio[785]: info: Jan 26 15:54:25 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:25 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:25 volumiokhv volumio[785]: info: sendMpdCommand status took 2 milliseconds Jan 26 15:54:25 volumiokhv volumio[785]: info: sendMpdCommand status took 1 milliseconds Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:25 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 15:54:25 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:25 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:25 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jan 26 15:54:25 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:25 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:25 volumiokhv volumio[785]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jan 26 15:54:25 volumiokhv volumio[785]: info: ------------------------------ 21ms Jan 26 15:54:25 volumiokhv volumio[785]: info: ------------------------------ 20ms Jan 26 15:54:26 volumiokhv volumio[785]: info: getStreamUrl took 1282 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand stop took 1 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand clear Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:54:26 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand clear took 1 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand load "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo" Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:54:26 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:54:26 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 3ms Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo" Jan 26 15:54:26 volumiokhv volumio[785]: error: updateQueue error: null Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:54:26 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 52ms Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo" took 2 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand play Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:54:26 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 4ms Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand play took 3 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 3ms Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand status took 7 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand status took 8 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:26 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:54:26 volumiokhv volumio[785]: verbose: CURRENT POSITION 1 Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus stop Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 23ms Jan 26 15:54:26 volumiokhv volumio[785]: info: Jan 26 15:54:26 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand status took 15 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 14 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: info: sendMpdCommand status took 4 milliseconds Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:54:26 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:54:26 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:26 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:54:26 volumiokhv volumio[785]: verbose: CURRENT POSITION 1 Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:54:26 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:26 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:26 volumiokhv volumio[785]: info: ------------------------------ 49ms Jan 26 15:54:27 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 43 milliseconds Jan 26 15:54:27 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 42 milliseconds Jan 26 15:54:27 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:27 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:54:27 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:27 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:54:27 volumiokhv volumio[785]: verbose: CURRENT POSITION 1 Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:54:27 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:27 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:54:27 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:54:27 volumiokhv volumio[785]: verbose: CURRENT POSITION 1 Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:54:27 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:54:27 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:54:27 volumiokhv volumio[785]: info: ------------------------------ 99ms Jan 26 15:54:27 volumiokhv volumio[785]: info: ------------------------------ 85ms Jan 26 15:54:41 volumiokhv volumio[785]: info: Tunnel connection is inactive, restarting it Jan 26 15:54:41 volumiokhv volumio[785]: info: Starting Tunnel 1 Jan 26 15:54:41 volumiokhv volumio[785]: info: Starting Tunnel Connection Checker Jan 26 15:54:41 volumiokhv sudo[1526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 26 15:54:41 volumiokhv sudo[1526]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:54:41 volumiokhv autossh[1096]: received signal to exit (15) Jan 26 15:54:41 volumiokhv systemd[1]: Stopping MyVolumio SSH Tunnel... Jan 26 15:54:41 volumiokhv systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Jan 26 15:54:41 volumiokhv systemd[1]: sshtunnel.service: Succeeded. Jan 26 15:54:41 volumiokhv systemd[1]: Stopped MyVolumio SSH Tunnel. Jan 26 15:54:41 volumiokhv systemd[1]: Started MyVolumio SSH Tunnel. Jan 26 15:54:41 volumiokhv sudo[1526]: pam_unix(sudo:session): session closed for user root Jan 26 15:54:41 volumiokhv volumio[785]: info: Remote SSH Started Jan 26 15:54:41 volumiokhv autossh[1529]: port set to 0, monitoring disabled Jan 26 15:54:41 volumiokhv autossh[1529]: starting ssh (count 1) Jan 26 15:54:41 volumiokhv autossh[1529]: ssh child pid is 1532 Jan 26 15:54:41 volumiokhv volumio[785]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jan 26 15:54:41 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:56:01 volumiokhv volumiossh-tunnel[1528]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Jan 26 15:56:52 volumiokhv volumio[785]: verbose: New Socket.io Connection to 192.168.1.65 from 192.168.1.215 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.175 Safari/537.36 Total Clients: 6 Jan 26 15:56:52 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetState Jan 26 15:56:52 volumiokhv volumio[785]: info: CoreCommandRouter::volumioGetQueue Jan 26 15:56:52 volumiokhv volumio[785]: info: CoreStateMachine::getQueue Jan 26 15:56:52 volumiokhv volumio[785]: info: CorePlayQueue::getQueue Jan 26 15:56:52 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Jan 26 15:56:57 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 1 Jan 26 15:56:57 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:56:57 volumiokhv volumio[785]: info: Prefetching next song Jan 26 15:56:57 volumiokhv volumio[785]: info: [1643212617985] ControllerQobuz::prefetch Jan 26 15:56:58 volumiokhv volumio[785]: info: getStreamUrl took 259 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand load "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU" Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU" Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand add "http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU" took 1 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 26 15:56:58 volumiokhv volumio[785]: info: Jan 26 15:56:58 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:56:58 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:56:58 volumiokhv volumio[785]: info: Jan 26 15:56:58 volumiokhv volumio[785]: ---------------------------- MPD announces state update: options Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand consume 1 took 1 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:56:58 volumiokhv volumio[785]: info: Jan 26 15:56:58 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:56:58 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:56:58 volumiokhv volumio[785]: info: ------------------------------ 3ms Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand status took 2 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: info: ------------------------------ 1ms Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:56:58 volumiokhv volumio[785]: info: Jan 26 15:56:58 volumiokhv volumio[785]: ---------------------------- MPD announces state update: options Jan 26 15:56:58 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand status took 1 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:56:58 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::startPlaybackTimer Jan 26 15:56:58 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:56:58 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:56:58 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":152244,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2193 Kbps","isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:56:58 volumiokhv volumio[785]: verbose: CURRENT POSITION 2 Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:56:58 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:56:58 volumiokhv volumio[785]: info: ------------------------------ 24ms Jan 26 15:56:58 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 18 milliseconds Jan 26 15:56:58 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:56:58 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:56:58 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":152244,"duration":156,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2193 Kbps","isStreaming":false,"title":"file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202425&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216066&hmac=FTTa7aXPL8rxKM8nzwMmbG4AsLo","trackType":"qobuz"} Jan 26 15:56:58 volumiokhv volumio[785]: verbose: CURRENT POSITION 2 Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:56:58 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:56:58 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:56:58 volumiokhv volumio[785]: info: ------------------------------ 38ms Jan 26 15:57:02 volumiokhv volumio[785]: info: Jan 26 15:57:02 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:57:02 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:57:02 volumiokhv volumio[785]: info: Jan 26 15:57:02 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:57:02 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:57:02 volumiokhv volumio[785]: info: Jan 26 15:57:02 volumiokhv volumio[785]: ---------------------------- MPD announces system playlist update Jan 26 15:57:02 volumiokhv volumio[785]: info: Ignoring MPD Status Update Jan 26 15:57:02 volumiokhv volumio[785]: info: Jan 26 15:57:02 volumiokhv volumio[785]: ---------------------------- MPD announces state update: player Jan 26 15:57:02 volumiokhv volumio[785]: info: ControllerMpd::getState Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand status Jan 26 15:57:02 volumiokhv volumio[785]: info: ------------------------------ 3ms Jan 26 15:57:02 volumiokhv volumio[785]: info: sendMpdCommand status took 3 milliseconds Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:57:02 volumiokhv volumio[785]: info: ------------------------------ 3ms Jan 26 15:57:02 volumiokhv volumio[785]: info: sendMpdCommand status took 3 milliseconds Jan 26 15:57:02 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::parseState Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:57:02 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:57:02 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":62,"duration":317,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2070 Kbps","isStreaming":false,"title":"file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU","trackType":"qobuz"} Jan 26 15:57:02 volumiokhv volumio[785]: verbose: CURRENT POSITION 2 Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:57:02 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:57:02 volumiokhv volumio[785]: info: ------------------------------ 21ms Jan 26 15:57:02 volumiokhv volumio[785]: info: sendMpdCommand playlistinfo took 16 milliseconds Jan 26 15:57:02 volumiokhv volumio[785]: verbose: ControllerMpd::parseTrackInfo Jan 26 15:57:02 volumiokhv volumio[785]: info: ControllerMpd::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::servicePushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CorePlayQueue::getTrack 2 Jan 26 15:57:02 volumiokhv volumio[785]: verbose: STATE SERVICE {"status":"play","position":0,"seek":62,"duration":317,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2070 Kbps","isStreaming":false,"title":"file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU","artist":null,"album":null,"uri":"http://streaming-std.qobuz.com:80/file?uid=1859117&eid=127202426&fmt=7&profile=raw&app_id=539451548&cid=1288724&etsp=1643216218&hmac=o4xgbr_Le_map-FPSZ5bmmEkfwU","trackType":"qobuz"} Jan 26 15:57:02 volumiokhv volumio[785]: verbose: CURRENT POSITION 2 Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::syncState stateService play Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::syncState currentStatus play Jan 26 15:57:02 volumiokhv volumio[785]: info: Received an update from plugin. extracting info from payload Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreStateMachine::pushState Jan 26 15:57:02 volumiokhv volumio[785]: info: CoreCommandRouter::volumioPushState Jan 26 15:57:02 volumiokhv volumio[785]: info: ------------------------------ 38ms Jan 26 15:58:46 volumiokhv volumio[785]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Jan 26 15:58:46 volumiokhv volumio[785]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Jan 26 15:58:46 volumiokhv sudo[2059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Jan 26 15:58:46 volumiokhv sudo[2059]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 26 15:58:47 volumiokhv sudo[2059]: pam_unix(sudo:session): session closed for user root Jan 26 15:58:52 volumiokhv sudo[2112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Jan 26 15:58:52 volumiokhv sudo[2112]: pam_unix(sudo:session): session opened for user root by (uid=0)