Thu Dec 5 21:15:04 UTC 2019 Description="'Adding two Tidal playlists the first with 20 titles there are 4 coming to the queue. The 2nd tidal list with more than 200 entries the green box adding to the queue is shown, but no title is moved. It looks like there is a timeout which prevents data coming to queue. '" # cat /proc/version --------------- Linux version 4.19.79+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1273 Fri Oct 11 18:03:05 BST 2019 # cat /etc/os-release --------------- PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="76976c3150e60fa37f55c84c5ca4b7a47b667b83" VOLUMIO_FE_VERSION="" VOLUMIO_BE_VERSION="2b418696ba9df7da37e66ecee4256e963897e4a2" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun Dec 1 01:32:00 CET 2019" VOLUMIO_VERSION="2.673" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="195d359258dcdb7969a22e2c84f33e21" # ifconfig --------------- eth0 Link encap:Ethernet HWaddr b8:27:eb:4a:d8:6d inet addr:192.168.2.89 Bcast:192.168.2.255 Mask:255.255.255.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:61739 errors:0 dropped:1416 overruns:0 frame:0 TX packets:39087 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:58464735 (55.7 MiB) TX bytes:8647911 (8.2 MiB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:65536 Metric:1 RX packets:2628 errors:0 dropped:0 overruns:0 frame:0 TX packets:2628 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:683706 (667.6 KiB) TX bytes:683706 (667.6 KiB) # sudo iwconfig --------------- lo no wireless extensions. eth0 no wireless extensions. # aplay -l --------------- xcb_connection_has_error() returned true **** List of PLAYBACK Hardware Devices **** card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA] Subdevices: 7/7 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 Subdevice #4: subdevice #4 Subdevice #5: subdevice #5 Subdevice #6: subdevice #6 card 0: ALSA [bcm2835 ALSA], device 1: bcm2835 IEC958/HDMI [bcm2835 IEC958/HDMI] Subdevices: 1/1 Subdevice #0: subdevice #0 card 0: ALSA [bcm2835 ALSA], device 2: bcm2835 IEC958/HDMI1 [bcm2835 IEC958/HDMI1] Subdevices: 1/1 Subdevice #0: subdevice #0 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 1 21:02 ? 00:00:11 /sbin/init root 2 0 0 21:02 ? 00:00:00 [kthreadd] root 3 2 0 21:02 ? 00:00:00 [kworker/0:0-cgr] root 6 2 0 21:02 ? 00:00:00 [mm_percpu_wq] root 7 2 0 21:02 ? 00:00:03 [ksoftirqd/0] root 8 2 0 21:02 ? 00:00:00 [kdevtmpfs] root 9 2 0 21:02 ? 00:00:00 [netns] root 11 2 0 21:02 ? 00:00:00 [khungtaskd] root 12 2 0 21:02 ? 00:00:00 [oom_reaper] root 13 2 0 21:02 ? 00:00:00 [writeback] root 14 2 0 21:02 ? 00:00:00 [kcompactd0] root 15 2 0 21:02 ? 00:00:00 [crypto] root 16 2 0 21:02 ? 00:00:00 [kblockd] root 17 2 0 21:02 ? 00:00:00 [watchdogd] root 18 2 0 21:02 ? 00:00:00 [rpciod] root 19 2 0 21:02 ? 00:00:00 [kworker/u3:0] root 20 2 0 21:02 ? 00:00:00 [xprtiod] root 23 2 0 21:02 ? 00:00:00 [kswapd0] root 24 2 0 21:02 ? 00:00:00 [nfsiod] root 35 2 0 21:02 ? 00:00:00 [kthrotld] root 36 2 0 21:02 ? 00:00:00 [iscsi_eh] root 37 2 0 21:02 ? 00:00:00 [dwc_otg] root 38 2 0 21:02 ? 00:00:00 [DWC Notificatio] root 39 2 0 21:02 ? 00:00:00 [vchiq-slot/0] root 40 2 0 21:02 ? 00:00:00 [vchiq-recy/0] root 41 2 0 21:02 ? 00:00:00 [vchiq-sync/0] root 42 2 0 21:02 ? 00:00:00 [vchiq-keep/0] root 43 2 0 21:02 ? 00:00:00 [SMIO] root 52 2 0 21:02 ? 00:00:00 [mmc_complete] root 53 2 0 21:02 ? 00:00:02 [kworker/0:1H-mm] root 78 2 0 21:02 ? 00:00:00 [jbd2/mmcblk0p2-] root 79 2 0 21:02 ? 00:00:00 [ext4-rsv-conver] root 81 2 0 21:02 ? 00:00:00 [kworker/0:3-eve] root 87 2 0 21:02 ? 00:00:03 [loop0] root 106 2 0 21:03 ? 00:00:00 [jbd2/mmcblk0p3-] root 107 2 0 21:03 ? 00:00:00 [ext4-rsv-conver] root 114 2 0 21:03 ? 00:00:00 [ipv6_addrconf] root 144 1 0 21:03 ? 00:00:05 /lib/systemd/systemd-journald root 171 1 0 21:03 ? 00:00:00 /lib/systemd/systemd-udevd root 199 2 0 21:03 ? 00:00:00 [SMIO] root 217 2 0 21:03 ? 00:00:00 [mmal-vchiq] root 218 2 0 21:03 ? 00:00:00 [mmal-vchiq] root 219 2 0 21:03 ? 00:00:00 [mmal-vchiq] root 275 2 0 21:03 ? 00:00:00 [kworker/u2:2-ev] root 293 2 0 21:03 ? 00:00:00 [cfg80211] root 461 1 0 21:03 ? 00:00:00 dhcpcd eth0 root 520 1 0 21:03 ? 00:00:00 /sbin/rpcbind -w statd 530 1 0 21:03 ? 00:00:00 /sbin/rpc.statd root 545 1 0 21:03 ? 00:00:00 /usr/sbin/rpc.idmapd root 547 1 0 21:03 ? 00:00:04 /usr/sbin/haveged --Foreground --verbose=1 --write=1024 volumio 550 1 0 21:03 ? 00:00:00 /usr/bin/udisks-glue --foreground volumio 553 1 0 21:03 ? 00:00:00 /usr/local/bin/volumio-remote-updater root 562 1 0 21:03 ? 00:00:00 /lib/systemd/systemd-logind avahi 589 1 0 21:03 ? 00:00:00 avahi-daemon: running [volumio.local] message+ 601 1 0 21:03 ? 00:00:01 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation avahi 624 589 0 21:03 ? 00:00:00 avahi-daemon: chroot helper root 633 1 0 21:03 ? 00:00:00 /usr/sbin/ifplugd -i eth0 -q -f -u0 -d10 -w -I ntp 650 1 0 21:03 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /var/lib/ntp/ntp.conf.dhcp -u 100:104 root 677 1 0 21:03 ? 00:00:00 /usr/lib/udisks/udisks-daemon --no-debug root 689 677 0 21:03 ? 00:00:00 udisks-daemon: not polling any devices root 701 1 0 21:03 ? 00:00:00 /usr/lib/policykit-1/polkitd --no-debug root 704 1 0 21:03 tty1 00:00:00 /bin/login -- root 705 1 0 21:03 ? 00:00:00 /sbin/agetty --keep-baud 115200 38400 9600 ttyAMA0 vt102 volumio 757 1 0 21:04 ? 00:00:00 /lib/systemd/systemd --user volumio 761 757 0 21:04 ? 00:00:00 (sd-pam) volumio 766 704 0 21:04 tty1 00:00:00 -bash volumio 776 1 17 21:04 ? 00:01:57 /usr/local/bin/node /volumio/index.js root 812 1 0 21:04 ? 00:00:00 /usr/sbin/winbindd root 813 812 0 21:04 ? 00:00:00 /usr/sbin/winbindd root 814 1 0 21:04 ? 00:00:00 /usr/sbin/nmbd -D root 815 814 0 21:04 ? 00:00:00 /usr/sbin/nmbd -D root 860 1 0 21:04 ? 00:00:00 /usr/sbin/smbd -D root 867 812 0 21:04 ? 00:00:00 /usr/sbin/winbindd root 868 812 0 21:04 ? 00:00:00 /usr/sbin/winbindd root 869 860 0 21:04 ? 00:00:00 /usr/sbin/smbd -D root 893 2 0 21:04 ? 00:00:00 [kworker/0:4-cgr] root 931 2 0 21:05 ? 00:00:00 [cifsiod] root 932 2 0 21:05 ? 00:00:00 [cifsoplockd] root 936 2 1 21:05 ? 00:00:09 [cifsd] volumio 964 776 0 21:05 ? 00:00:02 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 972 964 1 21:05 ? 00:00:06 /bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 989 766 2 21:05 tty1 00:00:15 top volumio 1053 1 0 21:05 ? 00:00:00 /usr/local/bin/shairport-sync volumio 1058 1 0 21:05 ? 00:00:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf volumio 1081 1 5 21:06 ? 00:00:26 /bin/streaming-daemon volumio 1117 1 0 21:06 ? 00:00:00 /bin/sh /tmp/sshtunnel.sh volumio 1118 1117 0 21:06 ? 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 8ioJFa12qEN17lInVq2mfmaZPa73-41e9ae114e8806dccb6d64d8ea90fe1e.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org volumio 1124 1118 0 21:06 ? 00:00:00 /usr/bin/ssh -o ServerAliveInterval 30 -o ServerAliveCountMax 3 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -N -p 2222 -R 8ioJFa12qEN17lInVq2mfmaZPa73-41e9ae114e8806dccb6d64d8ea90fe1e.eu1.myvolumio.org:8091:localhost:3000 eu1.myvolumio.org volumio 1158 1 0 21:06 ? 00:00:00 /bin/sh /bin/bt/btstart.sh start volumio 1181 1 0 21:06 ? 00:00:00 /usr/bin/pulseaudio rtkit 1182 1 0 21:06 ? 00:00:00 /usr/lib/rtkit/rtkit-daemon root 1186 1 0 21:07 ? 00:00:00 /usr/lib/bluetooth/bluetoothd volumio 1193 1158 0 21:07 ? 00:00:01 /usr/bin/python /bin/bt/simple-agent -c NoInputNoOutput root 1247 2 0 21:09 ? 00:00:00 [kworker/u2:0-ev] root 1250 2 0 21:09 ? 00:00:00 [kworker/0:0H] root 1277 2 0 21:12 ? 00:00:00 [kworker/0:1-eve] mpd 1278 1 18 21:12 ? 00:00:32 /usr/bin/mpd --no-daemon volumio 1346 776 1 21:15 ? 00:00:00 /bin/sh -c /usr/local/bin/node /volumio/logsubmit.js 'Adding two Tidal playlists the first with 20 titles there are 4 coming to the queue. The 2nd tidal list with more than 200 entries the green box adding to the queue is shown, but no title is moved. It looks like there is a timeout which prevents data coming to queue. ' volumio 1347 1346 73 21:15 ? 00:00:02 /usr/local/bin/node /volumio/logsubmit.js Adding two Tidal playlists the first with 20 titles there are 4 coming to the queue. The 2nd tidal list with more than 200 entries the green box adding to the queue is shown, but no title is moved. It looks like there is a timeout which prevents data coming to queue. volumio 1372 1347 0 21:15 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 1373 1372 0 21:15 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.2G 793M 1.3G 38% /imgpart /dev/loop0 337M 337M 0 100% /static overlay 13G 540M 12G 5% / devtmpfs 219M 0 219M 0% /dev tmpfs 233M 68K 233M 1% /dev/shm tmpfs 233M 4.7M 228M 3% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 233M 0 233M 0% /sys/fs/cgroup tmpfs 233M 40K 233M 1% /tmp tmpfs 233M 0 233M 0% /var/spool/cups tmpfs 20M 52K 20M 1% /var/log tmpfs 233M 0 233M 0% /var/spool/cups/tmp /dev/mmcblk0p1 61M 58M 2.3M 97% /boot tmpfs 47M 0 47M 0% /run/user/1000 //192.168.2.1/fritz.nas/IntensoEXT/Audio 3.6T 3.0T 698G 81% /mnt/NAS/nas # mount --------------- /dev/mmcblk0p2 on /imgpart type ext4 (rw,relatime,stripe=1024) /dev/loop0 on /static type squashfs (ro,relatime) overlay on / type overlay (rw,relatime,lowerdir=/mnt/static,upperdir=/mnt/ext/dyn,workdir=/mnt/ext/work) sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime) proc on /proc type proc (rw,relatime) devtmpfs on /dev type devtmpfs (rw,nosuid,size=223768k,nr_inodes=55942,mode=755) tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev,noexec) devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k) tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd) cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=22,pgrp=1,timeout=300,minproto=5,maxproto=5,direct) debugfs on /sys/kernel/debug type debugfs (rw,relatime) mqueue on /dev/mqueue type mqueue (rw,relatime) fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) tmpfs on /tmp type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups type tmpfs (rw,noatime,mode=755) tmpfs on /var/log type tmpfs (rw,nodev,relatime,size=20480k,mode=777,uid=1000,gid=4) tmpfs on /var/spool/cups/tmp type tmpfs (rw,noatime,mode=755) /dev/mmcblk0p1 on /boot type vfat (rw,nosuid,nodev,noexec,relatime,fmask=0111,dmask=0000,allow_utime=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro) rpc_pipefs on /run/rpc_pipefs type rpc_pipefs (rw,relatime) tmpfs on /run/user/1000 type tmpfs (rw,nosuid,nodev,relatime,size=47556k,mode=700,uid=1000,gid=1000) //192.168.2.1/fritz.nas/IntensoEXT/Audio on /mnt/NAS/nas type cifs (ro,relatime,vers=1.0,cache=strict,username=audioro,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.2.1,soft,unix,posixpaths,serverino,mapposix,acl,rsize=61440,wsize=65536,echo_interval=60,actimeo=1) # sudo journalctl -p 7 --------------- -- Logs begin at Sun 2019-12-01 00:32:00 UTC, end at Thu 2019-12-05 21:15:06 UTC. -- Dec 01 00:32:00 volumio systemd-journal[144]: Runtime journal is using 4.0M (max allowed 30.0M, trying to leave 34.8M free of 228.0M available → current limit 30.0M). Dec 01 00:32:00 volumio kernel: Booting Linux on physical CPU 0x0 Dec 01 00:32:00 volumio kernel: Linux version 4.19.79+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1273 Fri Oct 11 18:03:05 BST 2019 Dec 01 00:32:00 volumio kernel: CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d Dec 01 00:32:00 volumio kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache Dec 01 00:32:00 volumio kernel: OF: fdt: Machine model: Raspberry Pi Model B Rev 2 Dec 01 00:32:00 volumio kernel: Memory policy: Data cache writeback Dec 01 00:32:00 volumio kernel: cma: Reserved 8 MiB at 0x1c400000 Dec 01 00:32:00 volumio kernel: On node 0 totalpages: 122880 Dec 01 00:32:00 volumio kernel: Normal zone: 1080 pages used for memmap Dec 01 00:32:00 volumio kernel: Normal zone: 0 pages reserved Dec 01 00:32:00 volumio kernel: Normal zone: 122880 pages, LIFO batch:31 Dec 01 00:32:00 volumio kernel: random: get_random_bytes called from start_kernel+0x8c/0x49c with crng_init=0 Dec 01 00:32:00 volumio kernel: pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768 Dec 01 00:32:00 volumio kernel: pcpu-alloc: [0] 0 Dec 01 00:32:00 volumio kernel: Built 1 zonelists, mobility grouping on. Total pages: 121800 Dec 01 00:32:00 volumio kernel: Kernel command line: coherent_pool=1M bcm2708_fb.fbwidth=1600 bcm2708_fb.fbheight=1200 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 splash quiet plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh elevator=noop rootwait bootdelay=5 logo.nologo vt.global_cursor_default=0 loglevel=0 Dec 01 00:32:00 volumio kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) Dec 01 00:32:00 volumio kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) Dec 01 00:32:00 volumio kernel: Memory: 447536K/491520K available (6975K kernel code, 631K rwdata, 2080K rodata, 464K init, 797K bss, 35792K reserved, 8192K cma-reserved) Dec 01 00:32:00 volumio kernel: Virtual kernel memory layout: vector : 0xffff0000 - 0xffff1000 ( 4 kB) fixmap : 0xffc00000 - 0xfff00000 (3072 kB) vmalloc : 0xde800000 - 0xff800000 ( 528 MB) lowmem : 0xc0000000 - 0xde000000 ( 480 MB) modules : 0xbf000000 - 0xc0000000 ( 16 MB) .text : 0x(ptrval) - 0x(ptrval) (6976 kB) .init : 0x(ptrval) - 0x(ptrval) ( 464 kB) .data : 0x(ptrval) - 0x(ptrval) ( 632 kB) .bss : 0x(ptrval) - 0x(ptrval) ( 798 kB) Dec 01 00:32:00 volumio kernel: SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Dec 01 00:32:00 volumio kernel: ftrace: allocating 25203 entries in 74 pages Dec 01 00:32:00 volumio kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Dec 01 00:32:00 volumio kernel: sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns Dec 01 00:32:00 volumio kernel: clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns Dec 01 00:32:00 volumio kernel: bcm2835: system timer (irq = 27) Dec 01 00:32:00 volumio kernel: Console: colour dummy device 80x30 Dec 01 00:32:00 volumio kernel: console [tty1] enabled Dec 01 00:32:00 volumio kernel: Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792) Dec 01 00:32:00 volumio kernel: pid_max: default: 32768 minimum: 301 Dec 01 00:32:00 volumio kernel: Mount-cache hash table entries: 1024 (order: 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: CPU: Testing write buffer coherency: ok Dec 01 00:32:00 volumio kernel: Setting up static identity map for 0x8200 - 0x8238 Dec 01 00:32:00 volumio kernel: devtmpfs: initialized Dec 01 00:32:00 volumio kernel: VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5 Dec 01 00:32:00 volumio kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Dec 01 00:32:00 volumio kernel: futex hash table entries: 256 (order: -1, 3072 bytes) Dec 01 00:32:00 volumio kernel: pinctrl core: initialized pinctrl subsystem Dec 01 00:32:00 volumio kernel: NET: Registered protocol family 16 Dec 01 00:32:00 volumio kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Dec 01 00:32:00 volumio kernel: hw-breakpoint: found 6 breakpoint and 1 watchpoint registers. Dec 01 00:32:00 volumio kernel: hw-breakpoint: maximum watchpoint size is 4 bytes. Dec 01 00:32:00 volumio kernel: Serial: AMBA PL011 UART driver Dec 01 00:32:00 volumio kernel: bcm2835-mbox 2000b880.mailbox: mailbox enabled Dec 01 00:32:00 volumio kernel: bcm2835-dma 20007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1 Dec 01 00:32:00 volumio kernel: SCSI subsystem initialized Dec 01 00:32:00 volumio kernel: usbcore: registered new interface driver usbfs Dec 01 00:32:00 volumio kernel: usbcore: registered new interface driver hub Dec 01 00:32:00 volumio kernel: usbcore: registered new device driver usb Dec 01 00:32:00 volumio kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2019-10-11 18:40, variant start Dec 01 00:32:00 volumio kernel: raspberrypi-firmware soc:firmware: Firmware hash is 89cbed6a54e414b21b554ce245245744332c37e1 Dec 01 00:32:00 volumio kernel: clocksource: Switched to clocksource timer Dec 01 00:32:00 volumio kernel: VFS: Disk quotas dquot_6.6.0 Dec 01 00:32:00 volumio kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: FS-Cache: Loaded Dec 01 00:32:00 volumio kernel: CacheFiles: Loaded Dec 01 00:32:00 volumio kernel: NET: Registered protocol family 2 Dec 01 00:32:00 volumio kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: TCP established hash table entries: 4096 (order: 2, 16384 bytes) Dec 01 00:32:00 volumio kernel: TCP bind hash table entries: 4096 (order: 2, 16384 bytes) Dec 01 00:32:00 volumio kernel: TCP: Hash tables configured (established 4096 bind 4096) Dec 01 00:32:00 volumio kernel: UDP hash table entries: 256 (order: 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: UDP-Lite hash table entries: 256 (order: 0, 4096 bytes) Dec 01 00:32:00 volumio kernel: NET: Registered protocol family 1 Dec 01 00:32:00 volumio kernel: RPC: Registered named UNIX socket transport module. Dec 01 00:32:00 volumio kernel: RPC: Registered udp transport module. Dec 01 00:32:00 volumio kernel: RPC: Registered tcp transport module. Dec 01 00:32:00 volumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Dec 01 00:32:00 volumio kernel: Trying to unpack rootfs image as initramfs... Dec 01 00:32:00 volumio kernel: random: fast init done Dec 01 00:32:00 volumio kernel: Freeing initrd memory: 19368K Dec 01 00:32:00 volumio kernel: hw perfevents: no irqs for PMU, sampling events not supported Dec 01 00:32:00 volumio kernel: hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available Dec 01 00:32:00 volumio kernel: Initialise system trusted keyrings Dec 01 00:32:00 volumio kernel: workingset: timestamp_bits=14 max_order=17 bucket_order=3 Dec 01 00:32:00 volumio kernel: FS-Cache: Netfs 'nfs' registered for caching Dec 01 00:32:00 volumio kernel: NFS: Registering the id_resolver key type Dec 01 00:32:00 volumio kernel: Key type id_resolver registered Dec 01 00:32:00 volumio kernel: Key type id_legacy registered Dec 01 00:32:00 volumio kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Dec 01 00:32:00 volumio kernel: Key type asymmetric registered Dec 01 00:32:00 volumio kernel: Asymmetric key parser 'x509' registered Dec 01 00:32:00 volumio kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) Dec 01 00:32:00 volumio kernel: io scheduler noop registered (default) Dec 01 00:32:00 volumio kernel: io scheduler deadline registered Dec 01 00:32:00 volumio kernel: io scheduler cfq registered Dec 01 00:32:00 volumio kernel: io scheduler mq-deadline registered Dec 01 00:32:00 volumio kernel: io scheduler kyber registered Dec 01 00:32:00 volumio kernel: bcm2708_fb soc:fb: FB found 1 display(s) Dec 01 00:32:00 volumio kernel: Console: switching to colour frame buffer device 200x75 Dec 01 00:32:00 volumio kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 1600x1200 Dec 01 00:32:00 volumio kernel: bcm2835-rng 20104000.rng: hwrng registered Dec 01 00:32:00 volumio kernel: vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB) Dec 01 00:32:00 volumio kernel: vc-sm: Videocore shared memory driver Dec 01 00:32:01 volumio kernel: gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000 Dec 01 00:32:01 volumio kernel: brd: module loaded Dec 01 00:32:01 volumio kernel: loop: module loaded Dec 01 00:32:01 volumio kernel: Loading iSCSI transport class v2.0-870. Dec 01 00:32:01 volumio kernel: usbcore: registered new interface driver smsc95xx Dec 01 00:32:01 volumio kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Dec 01 00:32:01 volumio kernel: dwc_otg 20980000.usb: base=(ptrval) Dec 01 00:32:01 volumio kernel: Core Release: 2.80a Dec 01 00:32:01 volumio kernel: Setting default values for core params Dec 01 00:32:01 volumio kernel: Finished setting default values for core params Dec 01 00:32:01 volumio kernel: Using Buffer DMA mode Dec 01 00:32:01 volumio kernel: Periodic Transfer Interrupt Enhancement - disabled Dec 01 00:32:01 volumio kernel: Multiprocessor Interrupt Enhancement - disabled Dec 01 00:32:01 volumio kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Dec 01 00:32:01 volumio kernel: Dedicated Tx FIFOs mode Dec 01 00:32:01 volumio kernel: WARN::dwc_otg_hcd_init:1045: FIQ DMA bounce buffers: virt = dc514000 dma = 0x5c514000 len=9024 Dec 01 00:32:01 volumio kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Dec 01 00:32:01 volumio kernel: dwc_otg: Microframe scheduler enabled Dec 01 00:32:01 volumio kernel: WARN::hcd_init_fiq:457: FIQ on core 0 Dec 01 00:32:01 volumio kernel: WARN::hcd_init_fiq:458: FIQ ASM at c04fe2c8 length 36 Dec 01 00:32:01 volumio kernel: WARN::hcd_init_fiq:497: MPHI regs_base at de810000 Dec 01 00:32:01 volumio kernel: dwc_otg 20980000.usb: DWC OTG Controller Dec 01 00:32:01 volumio kernel: dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1 Dec 01 00:32:01 volumio kernel: dwc_otg 20980000.usb: irq 56, io mem 0x00000000 Dec 01 00:32:01 volumio kernel: Init: Port Power? op_state=1 Dec 01 00:32:01 volumio kernel: Init: Power Port (0) Dec 01 00:32:01 volumio kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19 Dec 01 00:32:01 volumio kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Dec 01 00:32:01 volumio kernel: usb usb1: Product: DWC OTG Controller Dec 01 00:32:01 volumio kernel: usb usb1: Manufacturer: Linux 4.19.79+ dwc_otg_hcd Dec 01 00:32:01 volumio kernel: usb usb1: SerialNumber: 20980000.usb Dec 01 00:32:01 volumio kernel: hub 1-0:1.0: USB hub found Dec 01 00:32:01 volumio kernel: hub 1-0:1.0: 1 port detected Dec 01 00:32:01 volumio kernel: dwc_otg: FIQ enabled Dec 01 00:32:01 volumio kernel: dwc_otg: NAK holdoff enabled Dec 01 00:32:01 volumio kernel: dwc_otg: FIQ split-transaction FSM enabled Dec 01 00:32:01 volumio kernel: Module dwc_common_port init Dec 01 00:32:01 volumio kernel: usbcore: registered new interface driver usb-storage Dec 01 00:32:01 volumio kernel: mousedev: PS/2 mouse device common for all mice Dec 01 00:32:01 volumio kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Dec 01 00:32:01 volumio kernel: bcm2835-cpufreq: min=700000 max=700000 Dec 01 00:32:01 volumio kernel: sdhci: Secure Digital Host Controller Interface driver Dec 01 00:32:01 volumio kernel: sdhci: Copyright(c) Pierre Ossman Dec 01 00:32:01 volumio kernel: sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe Dec 01 00:32:01 volumio kernel: sdhci-pltfm: SDHCI platform and OF driver helper Dec 01 00:32:01 volumio kernel: ledtrig-cpu: registered to indicate activity on CPUs Dec 01 00:32:01 volumio kernel: hidraw: raw HID events driver (C) Jiri Kosina Dec 01 00:32:01 volumio kernel: usbcore: registered new interface driver usbhid Dec 01 00:32:01 volumio kernel: usbhid: USB HID core driver Dec 01 00:32:01 volumio kernel: vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0 Dec 01 00:32:01 volumio kernel: [vc_sm_connected_init]: start Dec 01 00:32:01 volumio kernel: [vc_sm_connected_init]: end - returning 0 Dec 01 00:32:01 volumio kernel: Initializing XFRM netlink socket Dec 01 00:32:01 volumio kernel: NET: Registered protocol family 17 Dec 01 00:32:01 volumio kernel: Key type dns_resolver registered Dec 01 00:32:01 volumio kernel: registered taskstats version 1 Dec 01 00:32:01 volumio kernel: Loading compiled-in X.509 certificates Dec 01 00:32:01 volumio kernel: uart-pl011 20201000.serial: cts_event_workaround enabled Dec 01 00:32:01 volumio kernel: 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2 Dec 01 00:32:01 volumio kernel: console [ttyAMA0] enabled Dec 01 00:32:01 volumio kernel: sdhost: log_buf @ (ptrval) (5c513000) Dec 01 00:32:01 volumio kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Dec 01 00:32:01 volumio kernel: of_cfs_init Dec 01 00:32:01 volumio kernel: of_cfs_init: OK Dec 01 00:32:01 volumio kernel: Freeing unused kernel memory: 464K Dec 01 00:32:01 volumio kernel: This architecture does not have kernel memory protection. Dec 01 00:32:01 volumio kernel: Run /init as init process Dec 01 00:32:01 volumio kernel: mmc0: host does not support reading read-only switch, assuming write-enable Dec 01 00:32:01 volumio kernel: mmc0: new high speed SDHC card at address aaaa Dec 01 00:32:01 volumio kernel: mmcblk0: mmc0:aaaa SU16G 14.8 GiB Dec 01 00:32:01 volumio kernel: mmcblk0: p1 p2 p3 Dec 01 00:32:01 volumio kernel: Indeed it is in host mode hprt0 = 00021501 Dec 01 00:32:01 volumio kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Dec 01 00:32:01 volumio kernel: Indeed it is in host mode hprt0 = 00001101 Dec 01 00:32:01 volumio initramfs: Booting Volumio for BCM2835 Dec 01 00:32:01 volumio initramfs: This script mounts rootfs RO with an overlay RW layer. Dec 01 00:32:01 volumio kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Dec 01 00:32:01 volumio kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9512, bcdDevice= 2.00 Dec 01 00:32:01 volumio kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Dec 01 00:32:01 volumio kernel: hub 1-1:1.0: USB hub found Dec 01 00:32:01 volumio kernel: hub 1-1:1.0: 3 ports detected Dec 01 00:32:01 volumio kernel: fuse init (API version 7.27) Dec 01 00:32:01 volumio initramfs: IMGPART=/dev/mmcblk0p2 Dec 01 00:32:01 volumio initramfs: IMGFILE=/volumio_current.sqsh Dec 01 00:32:01 volumio initramfs: Boot delay (except first time) will be 5 seconds Dec 01 00:32:01 volumio initramfs: /dev/mmcblk0p2: Dec 01 00:32:01 volumio kernel: EXT4-fs (mmcblk0p2): recovery complete Dec 01 00:32:01 volumio kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) Dec 01 00:32:01 volumio initramfs: Doing a 5 second delay here to give kernel load a headstart Dec 01 00:32:01 volumio kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Dec 01 00:32:01 volumio kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Dec 01 00:32:01 volumio kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Dec 01 00:32:01 volumio kernel: smsc95xx v1.0.6 Dec 01 00:32:01 volumio kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-20980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:4a:d8:6d Dec 01 00:32:01 volumio kernel: usb 1-1.2: new full-speed USB device number 4 using dwc_otg Dec 01 00:32:01 volumio kernel: usb 1-1.2: New USB device found, idVendor=413c, idProduct=1003, bcdDevice= 2.00 Dec 01 00:32:01 volumio kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Dec 01 00:32:01 volumio kernel: usb 1-1.2: Product: Dell USB Keyboard Hub Dec 01 00:32:01 volumio kernel: usb 1-1.2: Manufacturer: Dell Dec 01 00:32:01 volumio kernel: hub 1-1.2:1.0: USB hub found Dec 01 00:32:01 volumio kernel: hub 1-1.2:1.0: 3 ports detected Dec 01 00:32:01 volumio kernel: usb 1-1.3: new high-speed USB device number 5 using dwc_otg Dec 01 00:32:01 volumio kernel: usb 1-1.3: New USB device found, idVendor=05e3, idProduct=0608, bcdDevice=32.98 Dec 01 00:32:01 volumio kernel: usb 1-1.3: New USB device strings: Mfr=0, Product=1, SerialNumber=0 Dec 01 00:32:01 volumio kernel: usb 1-1.3: Product: USB2.0 Hub Dec 01 00:32:01 volumio kernel: hub 1-1.3:1.0: USB hub found Dec 01 00:32:01 volumio kernel: hub 1-1.3:1.0: 4 ports detected Dec 01 00:32:01 volumio kernel: usb 1-1.2.1: new full-speed USB device number 6 using dwc_otg Dec 01 00:32:01 volumio kernel: usb 1-1.2.1: New USB device found, idVendor=413c, idProduct=2010, bcdDevice= 2.00 Dec 01 00:32:01 volumio kernel: usb 1-1.2.1: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Dec 01 00:32:01 volumio kernel: usb 1-1.2.1: Product: Dell USB Keyboard Dec 01 00:32:01 volumio kernel: usb 1-1.2.1: Manufacturer: Dell Dec 01 00:32:01 volumio kernel: input: Dell Dell USB Keyboard as /devices/platform/soc/20980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.0/0003:413C:2010.0001/input/input0 Dec 01 00:32:01 volumio kernel: hid-generic 0003:413C:2010.0001: input,hidraw0: USB HID v1.10 Keyboard [Dell Dell USB Keyboard] on usb-20980000.usb-1.2.1/input0 Dec 01 00:32:01 volumio kernel: input: Dell Dell USB Keyboard Consumer Control as /devices/platform/soc/20980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.1/0003:413C:2010.0002/input/input1 Dec 01 00:32:01 volumio kernel: input: Dell Dell USB Keyboard System Control as /devices/platform/soc/20980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.1/0003:413C:2010.0002/input/input2 Dec 01 00:32:01 volumio kernel: hid-generic 0003:413C:2010.0002: input,hidraw1: USB HID v1.10 Device [Dell Dell USB Keyboard] on usb-20980000.usb-1.2.1/input1 Dec 01 00:32:01 volumio kernel: usb 1-1.2.3: new low-speed USB device number 7 using dwc_otg Dec 01 00:32:01 volumio kernel: usb 1-1.2.3: New USB device found, idVendor=413c, idProduct=3010, bcdDevice= 2.30 Dec 01 00:32:01 volumio kernel: usb 1-1.2.3: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Dec 01 00:32:01 volumio kernel: input: HID 413c:3010 as /devices/platform/soc/20980000.usb/usb1/1-1/1-1.2/1-1.2.3/1-1.2.3:1.0/0003:413C:3010.0003/input/input3 Dec 01 00:32:01 volumio kernel: hid-generic 0003:413C:3010.0003: input,hidraw2: USB HID v1.10 Mouse [HID 413c:3010] on usb-20980000.usb-1.2.3/input0 Dec 01 00:32:01 volumio initramfs: Checking for USB updates Dec 01 00:32:01 volumio initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Dec 01 00:32:01 volumio kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Dec 01 00:32:01 volumio kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Dec 01 00:32:01 volumio kernel: EXT4-fs (mmcblk0p3): recovery complete Dec 01 00:32:01 volumio kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) Dec 01 00:32:01 volumio initramfs: With Option: Dec 01 00:32:01 volumio initramfs: VOLUMIO_VERSION="2.673" Dec 01 00:32:01 volumio initramfs: Finish initramfs, continue booting Volumio Dec 01 00:32:01 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Dec 01 00:32:01 volumio systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR) Dec 01 00:32:01 volumio systemd[1]: Detected architecture 'arm'. Dec 01 00:32:01 volumio kernel: NET: Registered protocol family 10 Dec 01 00:32:01 volumio kernel: Segment Routing with IPv6 Dec 01 00:32:01 volumio systemd[1]: Inserted module 'ipv6' Dec 01 00:32:01 volumio systemd[1]: Set hostname to . Dec 01 00:32:01 volumio kernel: uart-pl011 20201000.serial: no DMA platform data Dec 01 00:32:01 volumio kernel: random: systemd-sysv-ge: uninitialized urandom read (16 bytes read) Dec 01 00:32:01 volumio kernel: random: systemd: uninitialized urandom read (16 bytes read) Dec 01 00:32:01 volumio systemd[1]: [/lib/systemd/system/mpd.service:18] Unknown lvalue 'ProtectKernelTunables' in section 'Service' Dec 01 00:32:01 volumio systemd[1]: [/lib/systemd/system/mpd.service:19] Unknown lvalue 'ProtectControlGroups' in section 'Service' Dec 01 00:32:01 volumio systemd[1]: [/lib/systemd/system/mpd.service:20] Unknown lvalue 'ProtectKernelModules' in section 'Service' Dec 01 00:32:01 volumio systemd[1]: [/lib/systemd/system/mpd.service:23] Unknown lvalue 'RestrictNamespaces' in section 'Service' Dec 01 00:32:01 volumio systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory. Dec 01 00:32:01 volumio systemd[1]: Starting Forward Password Requests to Wall Directory Watch. Dec 01 00:32:01 volumio kernel: i2c /dev entries driver Dec 01 00:32:01 volumio systemd-journal[144]: Journal started Dec 01 00:32:01 volumio systemd[1]: Starting Slices. Dec 01 00:32:01 volumio systemd[1]: Reached target Slices. Dec 01 00:32:01 volumio systemd[1]: Starting Remount Root and Kernel File Systems... Dec 01 00:32:01 volumio systemd[1]: Started Restore / save the current clock. Dec 01 00:32:01 volumio systemd[1]: Started Create list of required static device nodes for the current kernel. Dec 01 00:32:01 volumio systemd-modules-load[140]: Inserted module 'i2c_dev' Dec 01 00:32:01 volumio systemd[1]: Started Load Kernel Modules. Dec 01 00:32:01 volumio systemd[1]: Time has been changed Dec 01 00:32:00 volumio systemd[1]: Mounted Debug File System. Dec 01 00:32:00 volumio systemd[1]: Mounted POSIX Message Queue File System. Dec 01 00:32:00 volumio systemd[1]: Started Remount Root and Kernel File Systems. Dec 01 00:32:01 volumio volumio[126]: 512 MB or less RAM Detected, need to enable swap Dec 01 00:32:01 volumio volumio[126]: Enabling Swap Dec 01 00:32:01 volumio volumio[126]: swapon: /data/swapfile: swapon failed: Invalid argument Dec 01 00:32:01 volumio volumio[126]: Setting swappiness to 40 Dec 01 00:32:01 volumio volumio[126]: vm.swappiness = 40 Dec 01 00:32:01 volumio fake-hwclock[131]: Sun Dec 1 00:32:00 UTC 2019 Dec 01 00:32:01 volumio systemd[1]: Started Various fixups to make systemd work better on Debian. Dec 01 00:32:01 volumio systemd[1]: Starting Load/Save Random Seed... Dec 01 00:32:01 volumio systemd[1]: Mounting FUSE Control File System... Dec 01 00:32:01 volumio systemd[1]: Mounting Configuration File System... Dec 01 00:32:01 volumio systemd[1]: Starting Apply Kernel Variables... Dec 01 00:32:01 volumio systemd[1]: Starting Create Static Device Nodes in /dev... Dec 01 00:32:01 volumio systemd[1]: Mounted FUSE Control File System. Dec 01 00:32:01 volumio systemd[1]: Mounted Configuration File System. Dec 01 00:32:01 volumio systemd[1]: Started Load/Save Random Seed. Dec 01 00:32:01 volumio systemd[1]: Started Apply Kernel Variables. Dec 01 00:32:01 volumio systemd[1]: Started Create Static Device Nodes in /dev. Dec 01 00:32:02 volumio systemd[1]: Starting udev Kernel Device Manager... Dec 01 00:32:02 volumio systemd[1]: Starting Local File Systems (Pre). Dec 01 00:32:02 volumio systemd[1]: Reached target Local File Systems (Pre). Dec 01 00:32:02 volumio systemd[1]: Mounting /tmp... Dec 01 00:32:02 volumio systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Dec 01 00:32:02 volumio systemd[1]: Mounting /var/spool/cups... Dec 01 00:32:02 volumio systemd[1]: Mounting /var/log... Dec 01 00:32:02 volumio systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Dec 01 00:32:02 volumio systemd-udevd[171]: starting version 215 Dec 01 00:32:02 volumio systemd[1]: Mounted /tmp. Dec 01 00:32:02 volumio systemd[1]: Started udev Kernel Device Manager. Dec 01 00:32:02 volumio systemd[1]: Mounted /var/spool/cups. Dec 01 00:32:02 volumio systemd[1]: Mounted /var/log. Dec 01 00:32:02 volumio systemd[1]: Mounting /var/spool/cups/tmp... Dec 01 00:32:02 volumio systemd[1]: Starting Show Plymouth Boot Screen... Dec 01 00:32:02 volumio systemd[1]: Starting Copy rules generated while the root was ro... Dec 01 00:32:02 volumio systemd[1]: Mounted /var/spool/cups/tmp. Dec 01 00:32:02 volumio systemd[1]: Started Copy rules generated while the root was ro. Dec 01 00:32:03 volumio systemd[1]: Started Show Plymouth Boot Screen. Dec 01 00:32:03 volumio systemd[1]: Starting Forward Password Requests to Plymouth Directory Watch. Dec 01 00:32:03 volumio systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Dec 01 00:32:03 volumio systemd[1]: Started Dispatch Password Requests to Console Directory Watch. Dec 01 00:32:03 volumio systemd[1]: Starting Paths. Dec 01 00:32:03 volumio systemd[1]: Reached target Paths. Dec 01 00:32:03 volumio kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:04 volumio kernel: media: Linux media interface: v0.10 Dec 01 00:32:04 volumio kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Dec 01 00:32:04 volumio kernel: [vc_sm_connected_init]: start Dec 01 00:32:04 volumio kernel: [vc_sm_connected_init]: installed successfully Dec 01 00:32:04 volumio kernel: videodev: Linux video capture interface: v2.00 Dec 01 00:32:04 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:04 volumio systemd[1]: Found device /dev/ttyAMA0. Dec 01 00:32:04 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:04 volumio kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:04 volumio kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Dec 01 00:32:05 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Dec 01 00:32:05 volumio kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Dec 01 00:32:05 volumio kernel: snd_bcm2835: unknown parameter 'index' ignored Dec 01 00:32:05 volumio kernel: bcm2835_audio soc:audio: card created with 8 channels Dec 01 00:32:06 volumio systemd[1]: Found device /dev/mmcblk0p1. Dec 01 00:32:06 volumio systemd[1]: Starting File System Check on /dev/mmcblk0p1... Dec 01 00:32:07 volumio systemd-fsck[234]: fsck.fat 3.0.27 (2014-11-12) Dec 01 00:32:07 volumio systemd-fsck[234]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt. Dec 01 00:32:07 volumio systemd-fsck[234]: Automatically removing dirty bit. Dec 01 00:32:07 volumio systemd-fsck[234]: Performing changes. Dec 01 00:32:07 volumio systemd-fsck[234]: /dev/mmcblk0p1: 226 files, 118345/123044 clusters Dec 01 00:32:07 volumio systemd[1]: Started File System Check on /dev/mmcblk0p1. Dec 01 00:32:07 volumio systemd[1]: Mounting /boot... Dec 01 00:32:07 volumio kernel: random: crng init done Dec 01 00:32:07 volumio kernel: random: 7 urandom warning(s) missed due to ratelimiting Dec 01 00:32:07 volumio systemd[1]: Mounted /boot. Dec 01 00:32:08 volumio systemd[1]: Starting Local File Systems. Dec 01 00:32:08 volumio systemd[1]: Reached target Local File Systems. Dec 01 00:32:08 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Dec 01 00:32:08 volumio systemd[1]: Starting Remote File Systems. Dec 01 00:32:08 volumio systemd[1]: Reached target Remote File Systems. Dec 01 00:32:08 volumio systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage... Dec 01 00:32:08 volumio systemd[1]: Starting Create Volatile Files and Directories... Dec 01 00:32:08 volumio systemd[1]: Starting LSB: Raise network interfaces.... Dec 01 00:32:08 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Dec 01 00:32:08 volumio systemd[1]: Started Create Volatile Files and Directories. Dec 01 00:32:08 volumio systemd[1]: Started Trigger Flushing of Journal to Persistent Storage. Dec 01 00:32:09 volumio systemd[1]: Starting system-ifup.slice. Dec 01 00:32:09 volumio systemd[1]: Created slice system-ifup.slice. Dec 01 00:32:09 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Dec 01 00:32:09 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Dec 01 00:32:09 volumio systemd[1]: Starting Sound Card. Dec 01 00:32:09 volumio systemd[1]: Reached target Sound Card. Dec 01 00:32:10 volumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Dec 01 00:32:11 volumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Dec 01 00:32:11 volumio kernel: platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 Dec 01 00:32:11 volumio kernel: cfg80211: failed to load regulatory.db Dec 01 00:32:11 volumio networking[255]: Configuring network interfaces...command failed: No such device (-19) Dec 01 00:32:11 volumio networking[255]: command failed: No such device (-19) Dec 01 00:32:13 volumio systemd[1]: Received SIGRTMIN+20 from PID 189 (plymouthd). Dec 01 00:32:13 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Dec 01 00:32:14 volumio networking[255]: command failed: No such device (-19) Dec 01 00:32:14 volumio networking[255]: dhcpcd[371]: version 6.0.5 starting Dec 01 00:32:14 volumio dhcpcd[371]: version 6.0.5 starting Dec 01 00:32:14 volumio networking[255]: dhcpcd[371]: eth0: waiting for carrier Dec 01 00:32:14 volumio dhcpcd[371]: eth0: waiting for carrier Dec 01 00:32:15 volumio kernel: smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x45E1 Dec 01 00:32:15 volumio dhcpcd[371]: eth0: carrier acquired Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: carrier acquired Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: rebinding lease of 192.168.2.89 Dec 01 00:32:15 volumio dhcpcd[371]: eth0: rebinding lease of 192.168.2.89 Dec 01 00:32:15 volumio dhcpcd[371]: eth0: leased 192.168.2.89 for 864000 seconds Dec 01 00:32:15 volumio dhcpcd[371]: eth0: adding host route to 192.168.2.89 via 127.0.0.1 Dec 01 00:32:15 volumio dhcpcd[371]: eth0: adding route to 192.168.2.0/24 Dec 01 00:32:15 volumio dhcpcd[371]: eth0: adding default route via 192.168.2.1 Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: leased 192.168.2.89 for 864000 seconds Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: adding host route to 192.168.2.89 via 127.0.0.1 Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: adding route to 192.168.2.0/24 Dec 01 00:32:15 volumio networking[255]: dhcpcd[371]: eth0: adding default route via 192.168.2.1 Dec 01 00:32:16 volumio networking[255]: dhcpcd[371]: forked to background, child pid 461 Dec 01 00:32:16 volumio dhcpcd[371]: forked to background, child pid 461 Dec 01 00:32:17 volumio networking[255]: done. Dec 01 00:32:17 volumio systemd[1]: Started LSB: Raise network interfaces.. Dec 01 00:32:17 volumio systemd[1]: Starting ifup for eth0... Dec 01 00:32:17 volumio systemd[1]: Started ifup for eth0. Dec 01 00:32:17 volumio systemd[1]: Starting Network. Dec 01 00:32:17 volumio systemd[1]: Reached target Network. Dec 01 00:32:17 volumio systemd[1]: Starting Network is Online. Dec 01 00:32:17 volumio systemd[1]: Reached target Network is Online. Dec 01 00:32:17 volumio systemd[1]: Starting LSB: RPC portmapper replacement... Dec 01 00:32:17 volumio ifup[507]: /sbin/ifup: interface eth0 already configured Dec 01 00:32:18 volumio rpcbind[508]: Starting rpcbind daemon.... Dec 01 00:32:18 volumio systemd[1]: Started LSB: RPC portmapper replacement. Dec 01 00:32:18 volumio systemd[1]: Starting RPC Port Mapper. Dec 01 00:32:18 volumio systemd[1]: Reached target RPC Port Mapper. Dec 01 00:32:18 volumio systemd[1]: Starting LSB: NFS support files common to client and server... Dec 01 00:32:18 volumio rpc.statd[530]: Version 1.2.8 starting Dec 01 00:32:18 volumio sm-notify[531]: Version 1.2.8 starting Dec 01 00:32:19 volumio kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de). Dec 01 00:32:19 volumio nfs-common[524]: Starting NFS common utilities: statd idmapd. Dec 01 00:32:19 volumio systemd[1]: Started LSB: NFS support files common to client and server. Dec 01 00:32:19 volumio systemd[1]: Starting System Initialization. Dec 01 00:32:19 volumio systemd[1]: Reached target System Initialization. Dec 01 00:32:19 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack Activation Socket. Dec 01 00:32:19 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Dec 01 00:32:19 volumio systemd[1]: Starting mpd.socket. Dec 01 00:32:19 volumio systemd[1]: Listening on mpd.socket. Dec 01 00:32:19 volumio systemd[1]: Starting D-Bus System Message Bus Socket. Dec 01 00:32:19 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Dec 01 00:32:19 volumio systemd[1]: Starting Sockets. Dec 01 00:32:19 volumio systemd[1]: Reached target Sockets. Dec 01 00:32:19 volumio systemd[1]: Starting Daily Cleanup of Temporary Directories. Dec 01 00:32:19 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Dec 01 00:32:19 volumio systemd[1]: Starting Timers. Dec 01 00:32:19 volumio systemd[1]: Reached target Timers. Dec 01 00:32:19 volumio systemd[1]: Started Manage Sound Card State (restore and store). Dec 01 00:32:19 volumio systemd[1]: Starting Restore Sound Card State... Dec 01 00:32:19 volumio systemd[1]: Starting Basic System. Dec 01 00:32:19 volumio systemd[1]: Reached target Basic System. Dec 01 00:32:19 volumio systemd[1]: Starting Entropy daemon using the HAVEGE algorithm... Dec 01 00:32:19 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Dec 01 00:32:19 volumio systemd[1]: Starting cd.service... Dec 01 00:32:19 volumio systemd[1]: Started cd.service. Dec 01 00:32:19 volumio systemd[1]: Started Configure Bluetooth Modems connected by UART. Dec 01 00:32:19 volumio systemd[1]: Starting Volumio Iptables Module... Dec 01 00:32:19 volumio systemd[1]: Started Volumio Iptables Module. Dec 01 00:32:19 volumio systemd[1]: Starting mount disks automatically with standby... Dec 01 00:32:19 volumio systemd[1]: Started mount disks automatically with standby. Dec 01 00:32:19 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Dec 01 00:32:20 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Dec 01 00:32:20 volumio systemd[1]: Starting volumio-remote-updater.service... Dec 01 00:32:20 volumio systemd[1]: Started volumio-remote-updater.service. Dec 01 00:32:20 volumio volumio[548]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 01 00:32:20 volumio systemd[1]: Starting Volumio SSH enabler... Dec 01 00:32:20 volumio systemd[1]: Started Volumio SSH enabler. Dec 01 00:32:20 volumio systemd[1]: Starting Wireless Services... Dec 01 00:32:20 volumio systemd[1]: Starting Xbindrc... Dec 01 00:32:20 volumio systemd[1]: Started Xbindrc. Dec 01 00:32:20 volumio systemd[1]: Starting /etc/rc.local Compatibility... Dec 01 00:32:20 volumio systemd[1]: Started getty on tty2-tty6 if dbus and logind are not available. Dec 01 00:32:20 volumio systemd[1]: Starting Login Service... Dec 01 00:32:20 volumio systemd[1]: Starting LSB: start Winbind daemon... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: start Samba daemons for the AD DC... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: Start NTP daemon... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: start Samba NetBIOS nameserver (nmbd)... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: Advanced IEEE 802.11 management daemon... Dec 01 00:32:21 volumio systemd[1]: Starting LSB: IPv4 DHCP client with IPv4LL support... Dec 01 00:32:21 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Dec 01 00:32:22 volumio systemd[1]: Starting Music Player Daemon... Dec 01 00:32:22 volumio systemd[1]: Starting D-Bus System Message Bus... Dec 01 00:32:22 volumio systemd[1]: Started D-Bus System Message Bus. Dec 01 00:32:23 volumio dhcpcd[586]: Not running dhcpcd because there is aleady an interface specific instance ... failed! Dec 01 00:32:23 volumio avahi-daemon[589]: Found user 'avahi' (UID 104) and group 'avahi' (GID 106). Dec 01 00:32:23 volumio dhcpcd[586]: /var/run/dhcpcd-eth0.pid ... failed! Dec 01 00:32:23 volumio avahi-daemon[589]: Successfully dropped root privileges. Dec 01 00:32:23 volumio avahi-daemon[589]: avahi-daemon 0.6.31 starting up. Dec 01 00:32:23 volumio ifplugd(eth0)[633]: ifplugd 0.28 initializing. Dec 01 00:32:23 volumio ifplugd(eth0)[633]: Using interface eth0/B8:27:EB:4A:D8:6D with driver (version: 22-Aug-2005) Dec 01 00:32:23 volumio ifplugd(eth0)[633]: Using detection mode: SIOCETHTOOL Dec 01 00:32:23 volumio ifplugd(eth0)[633]: Initialization complete, link beat detected. Dec 01 00:32:24 volumio ifplugd(eth0)[633]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Dec 01 00:32:24 volumio sudo[558]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 set power_save off Dec 01 00:32:24 volumio ifplugd(eth0)[633]: client: /sbin/ifup: interface eth0 already configured Dec 01 00:32:24 volumio ifplugd(eth0)[633]: Program executed successfully. Dec 01 00:32:24 volumio ifplugd[575]: Network Interface Plugging Daemon...start eth0...done. Dec 01 00:32:25 volumio ntpd[621]: ntpd 4.2.6p5@1.2349-o Mon Jul 25 22:35:28 UTC 2016 (1) Dec 01 00:32:25 volumio ntp[567]: Starting NTP server: ntpd. Dec 01 00:32:25 volumio sudo[558]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 00:32:25 volumio ntpd[650]: proto: precision = 1.000 usec Dec 01 00:32:25 volumio ntpd[650]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123 Dec 01 00:32:25 volumio avahi-daemon[589]: Successfully called chroot(). Dec 01 00:32:25 volumio avahi-daemon[589]: Successfully dropped remaining capabilities. Dec 01 00:32:25 volumio avahi-daemon[589]: No service file found in /etc/avahi/services. Dec 01 00:32:25 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Dec 01 00:32:25 volumio systemd[1]: Starting Permit User Sessions... Dec 01 00:32:25 volumio avahi-daemon[589]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.2.89. Dec 01 00:32:25 volumio avahi-daemon[589]: New relevant interface eth0.IPv4 for mDNS. Dec 01 00:32:25 volumio avahi-daemon[589]: Network interface enumeration completed. Dec 01 00:32:25 volumio avahi-daemon[589]: Registering new address record for 192.168.2.89 on eth0.IPv4. Dec 01 00:32:25 volumio dbus[601]: [system] Activating via systemd: service name='org.freedesktop.UDisks' unit='udisks.service' Dec 01 00:32:25 volumio avahi-daemon[589]: Registering HINFO record with values 'ARMV6L'/'LINUX'. Dec 01 00:32:25 volumio ntpd[650]: Listen and drop on 1 v6wildcard :: UDP 123 Dec 01 00:32:25 volumio ntpd[650]: Listen normally on 2 lo 127.0.0.1 UDP 123 Dec 01 00:32:25 volumio ntpd[650]: Listen normally on 3 eth0 192.168.2.89 UDP 123 Dec 01 00:32:25 volumio ntpd[650]: peers refreshed Dec 01 00:32:25 volumio ntpd[650]: Listening on routing socket on fd #20 for interface updates Dec 01 00:32:25 volumio sudo[558]: pam_unix(sudo:session): session closed for user root Dec 01 00:32:26 volumio systemd[1]: Started Restore Sound Card State. Dec 01 00:32:26 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 01 00:32:26 volumio systemd[1]: Unit cd.service entered failed state. Dec 01 00:32:26 volumio systemd[1]: Started /etc/rc.local Compatibility. Dec 01 00:32:26 volumio avahi-daemon[589]: Server startup complete. Host name is volumio.local. Local service cookie is 2377166466. Dec 01 00:32:26 volumio wifistart.sh[555]: command failed: No such device (-19) Dec 01 00:32:27 volumio loadcpufreq[574]: Loading cpufreq kernel modules...done (none). Dec 01 00:32:26 volumio systemd[1]: Started LSB: Start NTP daemon. Dec 01 00:32:27 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Dec 01 00:32:27 volumio systemd[1]: Started LSB: Brings up/down network automatically. Dec 01 00:32:27 volumio systemd[1]: Started LSB: Advanced IEEE 802.11 management daemon. Dec 01 00:32:27 volumio systemd[1]: dhcpcd.service: control process exited, code=exited status=6 Dec 01 00:32:27 volumio systemd[1]: Failed to start LSB: IPv4 DHCP client with IPv4LL support. Dec 01 00:32:27 volumio systemd[1]: Unit dhcpcd.service entered failed state. Dec 01 00:32:27 volumio systemd[1]: Started Permit User Sessions. Dec 01 00:32:27 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 01 00:32:28 volumio volumio-remote-updater[553]: Error: No active session Dec 01 00:32:28 volumio volumio-remote-updater[553]: [2019-12-01 00:32:28] [info] asio async_connect error: system:111 (Connection refused) Dec 01 00:32:28 volumio volumio-remote-updater[553]: [2019-12-01 00:32:28] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 01 00:32:28 volumio volumio-remote-updater[553]: [2019-12-01 00:32:28] [error] handle_connect error: Underlying Transport Error Dec 01 00:32:29 volumio volumio[552]: Could not open config: /tmp/upmpdcli.conf Dec 01 00:32:29 volumio systemd[1]: upmpdcli.service: main process exited, code=exited, status=1/FAILURE Dec 01 00:32:29 volumio systemd[1]: Unit upmpdcli.service entered failed state. Dec 01 00:32:30 volumio systemd-logind[562]: New seat seat0. Dec 01 00:32:30 volumio systemd[1]: Started Login Service. Dec 01 00:32:30 volumio systemd[1]: Starting Disk Manager (legacy version)... Dec 01 00:32:30 volumio systemd[1]: Stopping cd.service... Dec 01 00:32:30 volumio systemd[1]: Starting cd.service... Dec 01 00:32:31 volumio systemd[1]: Started cd.service. Dec 01 00:32:31 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Dec 01 00:32:31 volumio systemd[1]: Starting Hold until boot process finishes up... Dec 01 00:32:31 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Dec 01 00:32:31 volumio volumio[680]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 01 00:32:31 volumio systemd[1]: Received SIGRTMIN+21 from PID 189 (plymouthd). Dec 01 00:32:31 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 01 00:32:31 volumio systemd[1]: Unit cd.service entered failed state. Dec 01 00:32:31 volumio systemd[1]: Started Hold until boot process finishes up. Dec 01 00:32:32 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Dec 01 00:32:32 volumio dbus[601]: [system] Successfully activated service 'org.freedesktop.UDisks' Dec 01 00:32:32 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 01 00:32:32 volumio systemd[1]: Started Disk Manager (legacy version). Dec 01 00:32:32 volumio cpufrequtils[681]: CPUFreq Utilities: Setting performance CPUFreq governor...CPU0...done. Dec 01 00:32:32 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Dec 05 21:03:37 volumio dbus[601]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkitd.service' Dec 05 21:03:37 volumio systemd[1]: Time has been changed Dec 05 21:03:37 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:37 volumio systemd[1]: Starting Authenticate and Authorize Users to Run Privileged Tasks... Dec 05 21:03:37 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:37 volumio volumio-remote-updater[553]: [2019-12-05 21:03:37] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:03:37 volumio volumio-remote-updater[553]: [2019-12-05 21:03:37] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:03:37 volumio volumio-remote-updater[553]: [2019-12-05 21:03:37] [error] handle_connect error: Underlying Transport Error Dec 05 21:03:37 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:37 volumio systemd[1]: Started Xbindrc. Dec 05 21:03:37 volumio systemd[1]: Stopping cd.service... Dec 05 21:03:37 volumio systemd[1]: Starting cd.service... Dec 05 21:03:38 volumio systemd[1]: Started cd.service. Dec 05 21:03:38 volumio systemd[1]: Starting Getty on tty1... Dec 05 21:03:38 volumio systemd[1]: Started Getty on tty1. Dec 05 21:03:38 volumio systemd[1]: Starting Serial Getty on ttyAMA0... Dec 05 21:03:38 volumio systemd[1]: Started Serial Getty on ttyAMA0. Dec 05 21:03:38 volumio volumio[703]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 05 21:03:38 volumio systemd[1]: Starting Login Prompts. Dec 05 21:03:38 volumio systemd[1]: Reached target Login Prompts. Dec 05 21:03:38 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 05 21:03:38 volumio systemd[1]: Unit cd.service entered failed state. Dec 05 21:03:38 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 05 21:03:38 volumio systemd[1]: Stopping cd.service... Dec 05 21:03:38 volumio systemd[1]: Starting cd.service... Dec 05 21:03:38 volumio systemd[1]: Started cd.service. Dec 05 21:03:39 volumio volumio[709]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 05 21:03:39 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 05 21:03:39 volumio systemd[1]: Unit cd.service entered failed state. Dec 05 21:03:39 volumio polkitd[701]: started daemon version 0.105 using authority implementation `local' version `0.105' Dec 05 21:03:39 volumio dbus[601]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Dec 05 21:03:39 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 05 21:03:39 volumio systemd[1]: Started Authenticate and Authorize Users to Run Privileged Tasks. Dec 05 21:03:39 volumio systemd[1]: Stopping cd.service... Dec 05 21:03:39 volumio systemd[1]: Starting cd.service... Dec 05 21:03:39 volumio systemd[1]: Started cd.service. Dec 05 21:03:39 volumio volumio[716]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 05 21:03:39 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 05 21:03:39 volumio systemd[1]: Unit cd.service entered failed state. Dec 05 21:03:40 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 05 21:03:40 volumio systemd[1]: Stopping cd.service... Dec 05 21:03:40 volumio systemd[1]: Starting cd.service... Dec 05 21:03:40 volumio systemd[1]: Started cd.service. Dec 05 21:03:40 volumio volumio[718]: /bin/bash: /volumio/app/plugins/music_service/cd_controller/cd.sh: No such file or directory Dec 05 21:03:40 volumio systemd[1]: cd.service: main process exited, code=exited, status=127/n/a Dec 05 21:03:40 volumio systemd[1]: Unit cd.service entered failed state. Dec 05 21:03:40 volumio udisks-glue[550]: Device file /dev/mmcblk0 inserted Dec 05 21:03:40 volumio systemd[1]: cd.service holdoff time over, scheduling restart. Dec 05 21:03:41 volumio systemd[1]: Stopping cd.service... Dec 05 21:03:41 volumio systemd[1]: Starting cd.service... Dec 05 21:03:41 volumio systemd[1]: cd.service start request repeated too quickly, refusing to start. Dec 05 21:03:41 volumio systemd[1]: Failed to start cd.service. Dec 05 21:03:41 volumio systemd[1]: Unit cd.service entered failed state. Dec 05 21:03:41 volumio udisks-glue[550]: Device file /dev/mmcblk0p3 inserted Dec 05 21:03:42 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:42 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:42 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:42 volumio systemd[1]: Started Xbindrc. Dec 05 21:03:45 volumio volumio-remote-updater[553]: [2019-12-05 21:03:45] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:03:45 volumio volumio-remote-updater[553]: [2019-12-05 21:03:45] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:03:45 volumio volumio-remote-updater[553]: [2019-12-05 21:03:45] [error] handle_connect error: Underlying Transport Error Dec 05 21:03:46 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:46 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:46 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:46 volumio systemd[1]: Started Xbindrc. Dec 05 21:03:49 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:49 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:49 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:49 volumio systemd[1]: Started Xbindrc. Dec 05 21:03:53 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:53 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:53 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:53 volumio systemd[1]: Started Xbindrc. Dec 05 21:03:54 volumio haveged[547]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 4.8.2 CTV); collect: 128K Dec 05 21:03:54 volumio haveged[547]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 8/40; sz: 15248/74244 Dec 05 21:03:54 volumio haveged[547]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99988 Dec 05 21:03:54 volumio haveged[547]: haveged: fills: 0, generated: 0 Dec 05 21:03:55 volumio volumio-remote-updater[553]: [2019-12-05 21:03:55] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:03:55 volumio volumio-remote-updater[553]: [2019-12-05 21:03:55] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:03:55 volumio volumio-remote-updater[553]: [2019-12-05 21:03:55] [error] handle_connect error: Underlying Transport Error Dec 05 21:03:57 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:03:57 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:03:57 volumio systemd[1]: Starting Xbindrc... Dec 05 21:03:57 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:00 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:00 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:00 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:00 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:03 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:03 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:03 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:03 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:04 volumio login[704]: pam_lastlog(login:session): file /var/log/lastlog created Dec 05 21:04:05 volumio login[704]: pam_unix(login:session): session opened for user volumio by LOGIN(uid=0) Dec 05 21:04:05 volumio volumio-remote-updater[553]: [2019-12-05 21:04:05] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:04:05 volumio volumio-remote-updater[553]: [2019-12-05 21:04:05] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:04:05 volumio volumio-remote-updater[553]: [2019-12-05 21:04:05] [error] handle_connect error: Underlying Transport Error Dec 05 21:04:05 volumio systemd[1]: Starting user-1000.slice. Dec 05 21:04:05 volumio systemd[1]: Created slice user-1000.slice. Dec 05 21:04:05 volumio systemd[1]: Starting User Manager for UID 1000... Dec 05 21:04:05 volumio systemd-logind[562]: New session c1 of user volumio. Dec 05 21:04:05 volumio systemd[1]: Starting Session c1 of user volumio. Dec 05 21:04:05 volumio systemd[1]: Started Session c1 of user volumio. Dec 05 21:04:06 volumio systemd[757]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) Dec 05 21:04:07 volumio systemd[757]: Starting Paths. Dec 05 21:04:07 volumio systemd[757]: Reached target Paths. Dec 05 21:04:07 volumio systemd[757]: Starting Timers. Dec 05 21:04:07 volumio systemd[757]: Reached target Timers. Dec 05 21:04:07 volumio systemd[757]: Starting Sockets. Dec 05 21:04:07 volumio systemd[757]: Reached target Sockets. Dec 05 21:04:07 volumio systemd[757]: Starting Basic System. Dec 05 21:04:07 volumio systemd[757]: Reached target Basic System. Dec 05 21:04:07 volumio systemd[757]: Starting Default. Dec 05 21:04:07 volumio systemd[757]: Reached target Default. Dec 05 21:04:07 volumio systemd[757]: Startup finished in 925ms. Dec 05 21:04:07 volumio systemd[1]: Started User Manager for UID 1000. Dec 05 21:04:07 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:08 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:08 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:08 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:09 volumio wireless.js[669]: WIRELESS: No wireless interface, exiting Dec 05 21:04:09 volumio systemd[1]: wireless.service: control process exited, code=exited status=1 Dec 05 21:04:09 volumio systemd[1]: Failed to start Wireless Services. Dec 05 21:04:09 volumio systemd[1]: Unit wireless.service entered failed state. Dec 05 21:04:10 volumio systemd[1]: Starting Volumio Backend Module... Dec 05 21:04:10 volumio systemd[1]: Started Volumio Backend Module. Dec 05 21:04:10 volumio systemd[1]: Starting Volumio Streaming Daemon... Dec 05 21:04:10 volumio systemd[1]: Started Volumio Streaming Daemon. Dec 05 21:04:11 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:11 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:11 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:11 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:11 volumio systemd[1]: Started LSB: start Samba daemons for the AD DC. Dec 05 21:04:13 volumio volumio-streaming-daemon[777]: ############################ Dec 05 21:04:13 volumio volumio-streaming-daemon[777]: # Volumio Streaming Daemon # Dec 05 21:04:13 volumio volumio-streaming-daemon[777]: # Running on port 7777 # Dec 05 21:04:13 volumio volumio-streaming-daemon[777]: ############################ Dec 05 21:04:14 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:14 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:14 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:15 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:15 volumio volumio-remote-updater[553]: [2019-12-05 21:04:15] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:04:15 volumio volumio-remote-updater[553]: [2019-12-05 21:04:15] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:04:15 volumio volumio-remote-updater[553]: [2019-12-05 21:04:15] [error] handle_connect error: Underlying Transport Error Dec 05 21:04:17 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:17 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:17 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:17 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:18 volumio winbind[563]: Starting the Winbind daemon: winbindmkdir failed on directory /var/log/samba/cores: No such file or directory Dec 05 21:04:18 volumio winbind[563]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Dec 05 21:04:18 volumio winbind[563]: Unable to setup corepath for winbindd: No such file or directory Dec 05 21:04:18 volumio winbind[563]: mkdir failed on directory /var/log/samba/cores: No such file or directory Dec 05 21:04:18 volumio winbind[563]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Dec 05 21:04:18 volumio winbind[563]: Unable to setup corepath for winbindd: No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbind[563]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbind[563]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbindd[799]: [2019/12/05 21:04:18.145889, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbindd[799]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbindd[799]: [2019/12/05 21:04:18.149771, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbindd[799]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../source3/winbindd/winbindd.c:1549(main) Dec 05 21:04:18 volumio winbind[563]: winbindd version 4.2.14-Debian started. Dec 05 21:04:18 volumio winbind[563]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../lib/util/util.c:220(directory_create_or_exist) Dec 05 21:04:18 volumio winbind[563]: mkdir failed on directory /var/log/samba/cores: No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Dec 05 21:04:18 volumio winbind[563]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Dec 05 21:04:18 volumio winbind[563]: Unable to setup corepath for winbindd: No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18.145889, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbind[563]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbind[563]: [2019/12/05 21:04:18.149771, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbind[563]: Unable to open new log file '/var/log/samba/log.winbindd': No such file or directory Dec 05 21:04:18 volumio winbindd[812]: [2019/12/05 21:04:18.382700, 0] ../source3/winbindd/winbindd_cache.c:3235(initialize_winbindd_cache) Dec 05 21:04:18 volumio winbindd[812]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 05 21:04:18 volumio systemd[1]: Started LSB: start Winbind daemon. Dec 05 21:04:18 volumio winbind[563]: . Dec 05 21:04:18 volumio winbindd[812]: [2019/12/05 21:04:18.668966, 0] ../lib/util/become_daemon.c:124(daemon_ready) Dec 05 21:04:18 volumio winbindd[812]: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 05 21:04:18 volumio winbindd[813]: [2019/12/05 21:04:18.802714, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio winbindd[813]: Unable to open new log file '/var/log/samba/log.wb-VOLUMIO': No such file or directory Dec 05 21:04:18 volumio nmbd[571]: Starting NetBIOS name server: nmbdmkdir failed on directory /var/log/samba/cores: No such file or directory Dec 05 21:04:18 volumio nmbd[807]: [2019/12/05 21:04:18.876771, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio nmbd[807]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:18 volumio nmbd[571]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Dec 05 21:04:18 volumio nmbd[571]: Unable to setup corepath for nmbd: No such file or directory Dec 05 21:04:18 volumio nmbd[571]: [2019/12/05 21:04:18, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:19 volumio nmbd[571]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:19 volumio nmbd[571]: [2019/12/05 21:04:18, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:19 volumio nmbd[571]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:19 volumio nmbd[571]: [2019/12/05 21:04:18, 0] ../source3/nmbd/nmbd.c:908(main) Dec 05 21:04:19 volumio nmbd[571]: nmbd version 4.2.14-Debian started. Dec 05 21:04:19 volumio nmbd[571]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Dec 05 21:04:19 volumio nmbd[571]: [2019/12/05 21:04:18.876771, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:19 volumio nmbd[571]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:18 volumio nmbd[807]: [2019/12/05 21:04:18.953247, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:18 volumio nmbd[807]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:19 volumio nmbd[814]: [2019/12/05 21:04:19.026851, 0] ../source3/nmbd/asyncdns.c:157(start_async_dns) Dec 05 21:04:19 volumio nmbd[814]: started asyncdns process 815 Dec 05 21:04:19 volumio systemd[1]: Started LSB: start Samba NetBIOS nameserver (nmbd). Dec 05 21:04:19 volumio systemd[1]: Starting LSB: start Samba SMB/CIFS daemon (smbd)... Dec 05 21:04:19 volumio nmbd[571]: [2019/12/05 21:04:18.953247, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:19 volumio nmbd[571]: Unable to open new log file '/var/log/samba/log.nmbd': No such file or directory Dec 05 21:04:19 volumio nmbd[814]: [2019/12/05 21:04:19.284197, 0] ../lib/util/become_daemon.c:124(daemon_ready) Dec 05 21:04:19 volumio nmbd[814]: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 05 21:04:19 volumio nmbd[571]: . Dec 05 21:04:20 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:20 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:20 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:20 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:22 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:22 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:22 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:22 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:25 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:25 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:25 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:25 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:25 volumio volumio-remote-updater[553]: [2019-12-05 21:04:25] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:04:25 volumio volumio-remote-updater[553]: [2019-12-05 21:04:25] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:04:25 volumio volumio-remote-updater[553]: [2019-12-05 21:04:25] [error] handle_connect error: Underlying Transport Error Dec 05 21:04:27 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:27 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:27 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:27 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:29 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:29 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:29 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:29 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:31 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:31 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:31 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:31 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:34 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:34 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:34 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:34 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:35 volumio volumio-remote-updater[553]: [2019-12-05 21:04:35] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:04:35 volumio volumio-remote-updater[553]: [2019-12-05 21:04:35] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:04:35 volumio volumio-remote-updater[553]: [2019-12-05 21:04:35] [error] handle_connect error: Underlying Transport Error Dec 05 21:04:36 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:36 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:36 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:36 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:38 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:38 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:38 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:38 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:40 volumio smbd[816]: Starting SMB/CIFS daemon: smbd[2019/12/05 21:04:40, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[816]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40, 0] ../lib/util/util.c:220(directory_create_or_exist) Dec 05 21:04:40 volumio smbd[816]: mkdir failed on directory /var/log/samba/cores: No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40, 0] ../source3/lib/dumpcore.c:59(get_default_corepath) Dec 05 21:04:40 volumio smbd[816]: Failed to create /var/log/samba/cores for user 0 with mode 0700 Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40, 0] ../source3/lib/dumpcore.c:250(dump_core_setup) Dec 05 21:04:40 volumio smbd[816]: Unable to setup corepath for smbd: No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[816]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40, 0] ../source3/smbd/server.c:1241(main) Dec 05 21:04:40 volumio smbd[816]: smbd version 4.2.14-Debian started. Dec 05 21:04:40 volumio smbd[816]: Copyright Andrew Tridgell and the Samba Team 1992-2014 Dec 05 21:04:40 volumio smbd[852]: [2019/12/05 21:04:40.502414, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[852]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40.502414, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[816]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[852]: [2019/12/05 21:04:40.532947, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[852]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[852]: [2019/12/05 21:04:40.533922, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[852]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40.532947, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[816]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio smbd[816]: [2019/12/05 21:04:40.533922, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:40 volumio smbd[816]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:40 volumio systemd[1]: Started LSB: start Samba SMB/CIFS daemon (smbd). Dec 05 21:04:40 volumio smbd[816]: . Dec 05 21:04:40 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:40 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:41 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:41 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:41 volumio winbindd[867]: [2019/12/05 21:04:41.313000, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:41 volumio winbindd[867]: Unable to open new log file '/var/log/samba/log.winbindd-idmap': No such file or directory Dec 05 21:04:41 volumio winbindd[868]: [2019/12/05 21:04:41.663189, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:41 volumio winbindd[868]: Unable to open new log file '/var/log/samba/log.wb-BUILTIN': No such file or directory Dec 05 21:04:42 volumio smbd[860]: [2019/12/05 21:04:42.236417, 0] ../lib/util/become_daemon.c:124(daemon_ready) Dec 05 21:04:42 volumio smbd[860]: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 05 21:04:42 volumio smbd[869]: [2019/12/05 21:04:42.309137, 0] ../lib/util/debug.c:603(reopen_logs_internal) Dec 05 21:04:42 volumio smbd[869]: Unable to open new log file '/var/log/samba/log.smbd': No such file or directory Dec 05 21:04:43 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:43 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:43 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:43 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:44 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:44 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:44 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:44 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:45 volumio volumio-remote-updater[553]: [2019-12-05 21:04:45] [info] asio async_connect error: system:111 (Connection refused) Dec 05 21:04:45 volumio volumio-remote-updater[553]: [2019-12-05 21:04:45] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 05 21:04:45 volumio volumio-remote-updater[553]: [2019-12-05 21:04:45] [error] handle_connect error: Underlying Transport Error Dec 05 21:04:46 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:46 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:46 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:46 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:48 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:48 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:48 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:48 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:50 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:50 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:50 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:50 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:52 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:52 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:52 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:52 volumio systemd[1]: Started Xbindrc. Dec 05 21:04:53 volumio systemd[1]: xbindkeysrc.service holdoff time over, scheduling restart. Dec 05 21:04:53 volumio systemd[1]: Stopping Xbindrc... Dec 05 21:04:53 volumio systemd[1]: Starting Xbindrc... Dec 05 21:04:53 volumio systemd[1]: xbindkeysrc.service start request repeated too quickly, refusing to start. Dec 05 21:04:53 volumio systemd[1]: Failed to start Xbindrc. Dec 05 21:04:53 volumio systemd[1]: Unit xbindkeysrc.service entered failed state. Dec 05 21:04:55 volumio volumio-remote-updater[553]: [2019-12-05 21:04:55] [connect] Successful connection Dec 05 21:04:56 volumio systemd[1]: mpd.service start operation timed out. Terminating. Dec 05 21:04:56 volumio systemd[1]: Failed to start Music Player Daemon. Dec 05 21:04:56 volumio systemd[1]: Unit mpd.service entered failed state. Dec 05 21:04:56 volumio systemd[1]: Starting Multi-User System. Dec 05 21:04:56 volumio systemd[1]: Reached target Multi-User System. Dec 05 21:04:56 volumio systemd[1]: Starting Graphical Interface. Dec 05 21:04:56 volumio systemd[1]: Reached target Graphical Interface. Dec 05 21:04:56 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 05 21:04:56 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 05 21:04:56 volumio systemd[1]: Startup finished in 11.348s (kernel) + 1min 54.524s (userspace) = 2min 5.872s. Dec 05 21:04:57 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:04:57 volumio volumio[776]: info: ----- Volumio2 ---- Dec 05 21:04:57 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:04:57 volumio volumio[776]: info: ----- System startup ---- Dec 05 21:04:57 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:04:57 volumio volumio[776]: info: MYVOLUMIO Environment detected Dec 05 21:05:04 volumio volumio[776]: info: Plugin folders cleanup Dec 05 21:05:04 volumio volumio[776]: info: Scanning into folder /volumio/app/plugins/ Dec 05 21:05:04 volumio volumio[776]: info: Scanning category audio_interface Dec 05 21:05:04 volumio volumio[776]: info: Scanning category miscellanea Dec 05 21:05:04 volumio volumio[776]: info: Scanning category music_service Dec 05 21:05:04 volumio volumio[776]: info: Scanning category plugins.json Dec 05 21:05:04 volumio volumio[776]: info: Scanning category system_controller Dec 05 21:05:04 volumio volumio[776]: info: Scanning category user_interface Dec 05 21:05:04 volumio volumio[776]: info: Scanning into folder /data/plugins/ Dec 05 21:05:04 volumio volumio[776]: info: Scanning category system_controller Dec 05 21:05:04 volumio volumio[776]: info: Plugin folders cleanup completed Dec 05 21:05:04 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:05:04 volumio volumio[776]: info: ----- Core plugins startup ---- Dec 05 21:05:04 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:05:04 volumio volumio[776]: info: Loading plugins from folder /volumio/app/plugins/ Dec 05 21:05:04 volumio volumio[776]: info: Adding plugin upnp to MyMusic Plugins Dec 05 21:05:04 volumio volumio[776]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 05 21:05:04 volumio volumio[776]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 05 21:05:04 volumio volumio[776]: info: Loading plugins from folder /data/plugins/ Dec 05 21:05:04 volumio volumio[776]: info: Loading plugin "system"... Dec 05 21:05:04 volumio volumio[776]: info: Loading plugin "appearance"... Dec 05 21:05:09 volumio volumio[776]: info: Loading plugin "network"... Dec 05 21:05:10 volumio volumio-remote-updater[553]: [2019-12-05 21:05:10] [connect] Successful connection Dec 05 21:05:11 volumio volumio[776]: info: Loading plugin "services"... Dec 05 21:05:12 volumio volumio[776]: info: Loading plugin "alsa_controller"... Dec 05 21:05:12 volumio volumio[776]: info: Loading plugin "wizard"... Dec 05 21:05:12 volumio volumio[776]: info: Loading plugin "volumio_command_line_client"... Dec 05 21:05:12 volumio volumio[776]: info: Loading plugin "upnp"... Dec 05 21:05:13 volumio volumio[776]: info: [1575579912999] Starting Upmpd Daemon Dec 05 21:05:13 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:05:13 volumio volumio[776]: info: Loading plugin "my_music"... Dec 05 21:05:13 volumio volumio[776]: info: Loading plugin "mpd"... Dec 05 21:05:15 volumio volumio[776]: info: Loading plugin "upnp_browser"... Dec 05 21:05:18 volumio volumio[776]: info: Loading plugin "networkfs"... Dec 05 21:05:19 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:05:19 volumio volumio[776]: info: Loading plugin "alarm-clock"... Dec 05 21:05:19 volumio sudo[922]: 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,vers=1.0 //192.168.2.1/fritz.nas/IntensoEXT/Audio /mnt/NAS/nas Dec 05 21:05:19 volumio sudo[922]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:19 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching Dec 05 21:05:19 volumio kernel: Key type cifs.spnego registered Dec 05 21:05:19 volumio kernel: Key type cifs.idmap registered Dec 05 21:05:20 volumio sudo[922]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:21 volumio volumio[776]: info: Loading plugin "airplay_emulation"... Dec 05 21:05:21 volumio volumio[776]: info: Starting Shairport Sync Dec 05 21:05:21 volumio volumio[776]: info: Loading plugin "last_100"... Dec 05 21:05:21 volumio volumio[776]: info: Loading plugin "webradio"... Dec 05 21:05:22 volumio volumio[776]: info: Loading plugin "i2s_dacs"... Dec 05 21:05:22 volumio volumio[776]: info: I2S DAC not set, start Auto-detection Dec 05 21:05:22 volumio volumio[776]: info: Loading plugin "volumiodiscovery"... Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:05:23 volumio node[776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 05 21:05:23 volumio node[776]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:05:23 volumio node[776]: *** WARNING *** For more information see Dec 05 21:05:23 volumio node[776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:05:23 volumio node[776]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:05:23 volumio node[776]: *** WARNING *** For more information see Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** For more information see Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 05 21:05:23 volumio volumio[776]: *** WARNING *** For more information see Dec 05 21:05:23 volumio volumio[776]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 05 21:05:23 volumio volumio[776]: Discovery: StartAdv! undefined Dec 05 21:05:23 volumio volumio[776]: Discovery: Started advertising... Volumio - undefined Dec 05 21:05:23 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:05:23 volumio volumio[776]: info: Loading plugin "outputs"... Dec 05 21:05:23 volumio volumio[776]: info: Loading plugin "albumart"... Dec 05 21:05:23 volumio volumio[776]: info: Plugin example_plugin is not enabled Dec 05 21:05:23 volumio volumio[776]: info: Loading plugin "inputs"... Dec 05 21:05:23 volumio volumio[776]: info: Loading plugin "updater_comm"... Dec 05 21:05:25 volumio volumio-remote-updater[553]: [2019-12-05 21:05:25] [connect] Successful connection Dec 05 21:05:25 volumio volumio[776]: info: Plugin mpdemulation is not enabled Dec 05 21:05:25 volumio volumio[776]: info: Loading plugin "rest_api"... Dec 05 21:05:26 volumio volumio[776]: info: Loading plugin "websocket"... Dec 05 21:05:26 volumio volumio[776]: info: Loading plugin "backup_restore"... Dec 05 21:05:28 volumio volumio[776]: Forking 1 albumart workers Dec 05 21:05:30 volumio volumio[776]: info: ___________ START PLUGINS ___________ Dec 05 21:05:30 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:05:30 volumio volumio[776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:05:30 volumio volumio[776]: info: [1575579930294] CoreMusicLibrary::Adding element Media Servers Dec 05 21:05:30 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:05:31 volumio volumio[776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:05:31 volumio volumio[776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:05:31 volumio volumio[776]: info: [1575579931512] CoreMusicLibrary::Adding element Last_100 Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:05:31 volumio volumio[776]: info: [1575579931555] CoreMusicLibrary::Adding element Webradio Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:05:31 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:05:31 volumio volumio[776]: info: ----- MyVolumio plugins startup ---- Dec 05 21:05:31 volumio volumio[776]: info: ------------------------------------------- Dec 05 21:05:31 volumio volumio[776]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 05 21:05:31 volumio volumio[776]: info: Loading i18n strings for locale de Dec 05 21:05:31 volumio volumio[776]: Updating browse sources language Dec 05 21:05:31 volumio volumio[776]: Cannot find translation for sourceMedia Servers Dec 05 21:05:31 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::initPlayerControls Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:32 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 21:05:33 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:05:33 volumio volumio[776]: info: BOOT COMPLETED Dec 05 21:05:33 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:05:35 volumio volumio[776]: Starting albumart workers Dec 05 21:05:38 volumio volumio[776]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Dec 05 21:05:38 volumio volumio[776]: info: CoreCommandRouter::Close All Modals sent Dec 05 21:05:38 volumio volumio[776]: info: CoreCommandRouter::Close All Modals sent Dec 05 21:05:38 volumio volumio[776]: Express server listening on port 3000 Dec 05 21:05:38 volumio volumio[776]: Volumio Calling Home Dec 05 21:05:39 volumio volumio[776]: info: CoreStateMachine::resetVolumioState Dec 05 21:05:39 volumio volumio[776]: info: CoreStateMachine::getcurrentVolume Dec 05 21:05:39 volumio volumio[776]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:05:40 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 05 21:05:40 volumio sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:05:40 volumio volumio-remote-updater[553]: [2019-12-05 21:05:40] [connect] Successful connection Dec 05 21:05:40 volumio sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:40 volumio sudo[1002]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:40 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 05 21:05:42 volumio volumio[776]: info: Volumio called home Dec 05 21:05:42 volumio volumio[776]: info: Setting Device type: Raspberry PI Dec 05 21:05:43 volumio volumio[776]: info: Cannot initialize MPD Connection: MPD is not running Dec 05 21:05:43 volumio sudo[1019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cdetect -y 1 Dec 05 21:05:43 volumio sudo[1019]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:43 volumio sudo[1019]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:44 volumio volumio-remote-updater[553]: [2019-12-05 21:05:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1575579940 101 Dec 05 21:05:44 volumio volumio[776]: info: VolumeController:: Volume=40 Mute =false Dec 05 21:05:44 volumio volumio[776]: info: CoreStateMachine::pushState Dec 05 21:05:44 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:05:44 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:05:44 volumio volumio[776]: info: CoreCommandRouter::volumioPushState Dec 05 21:05:44 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:05:44 volumio volumio[776]: info: CoreStateMachine::updateTrackBlock Dec 05 21:05:44 volumio volumio[776]: info: CorePlayQueue::getTrackBlock Dec 05 21:05:44 volumio volumio[776]: info: CoreCommandRouter::volumioRetrievevolume Dec 05 21:05:45 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:05:45 volumio volumio[776]: info: Reloading queue from file Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::setRepeat null single undefined Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::pushState Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:05:46 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::volumioPushState Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::setRandom null Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::pushState Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:05:46 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::volumioPushState Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:05:46 volumio volumio[776]: info: VolumeController:: Volume=40 Mute =false Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::pushState Dec 05 21:05:46 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:05:46 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::volumioPushState Dec 05 21:05:46 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 05 21:05:47 volumio sudo[1031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay Dec 05 21:05:47 volumio sudo[1031]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:47 volumio sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay Dec 05 21:05:47 volumio systemd[1]: Starting ShairportSync AirTunes receiver... Dec 05 21:05:47 volumio systemd[1]: Started ShairportSync AirTunes receiver. Dec 05 21:05:47 volumio sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:47 volumio sudo[1031]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:47 volumio sudo[1035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 05 21:05:47 volumio sudo[1035]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:48 volumio systemd[1]: Stopping ShairportSync AirTunes receiver... Dec 05 21:05:48 volumio systemd[1]: Starting ShairportSync AirTunes receiver... Dec 05 21:05:48 volumio systemd[1]: Started ShairportSync AirTunes receiver. Dec 05 21:05:48 volumio sudo[1033]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:48 volumio shairport-sync[1053]: Successful Startup Dec 05 21:05:48 volumio systemd[1]: Starting UPnP Renderer front-end to MPD... Dec 05 21:05:48 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Dec 05 21:05:48 volumio sudo[1035]: pam_unix(sudo:session): session closed for user root Dec 05 21:05:48 volumio volumio[776]: Discovery: adding 8aa31b8a-dd3c-48ef-9766-ba973e28234f Dec 05 21:05:48 volumio volumio[776]: info: mDNS: Found device Volumio Dec 05 21:05:49 volumio sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 05 21:05:49 volumio volumio[776]: info: Adding plugin bluetooth to MyMusic Plugins Dec 05 21:05:49 volumio sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:05:49 volumio volumio[776]: info: Adding plugin cd_controller to MyMusic Plugins Dec 05 21:05:49 volumio volumio[776]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 05 21:05:49 volumio volumio[776]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 05 21:05:49 volumio sudo[1064]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:01 volumio volumio[776]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 05 21:06:10 volumio volumio[776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 05 21:06:10 volumio volumio[776]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 05 21:06:10 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:10 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:10 volumio volumio[776]: info: Starting MyVolumio Remote Streaming Endpoints Dec 05 21:06:10 volumio volumio[776]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 05 21:06:10 volumio volumio[776]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 05 21:06:10 volumio volumio[776]: info: Streaming services startup Dec 05 21:06:10 volumio volumio[776]: info: Starting Streaming Daemon Dec 05 21:06:10 volumio volumio[776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 05 21:06:10 volumio sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 05 21:06:10 volumio sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:10 volumio systemd[1]: Stopping Volumio Streaming Daemon... Dec 05 21:06:11 volumio systemd[1]: Starting Volumio Streaming Daemon... Dec 05 21:06:11 volumio systemd[1]: Started Volumio Streaming Daemon. Dec 05 21:06:11 volumio sudo[1075]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:11 volumio volumio-streaming-daemon[1081]: ############################ Dec 05 21:06:11 volumio volumio-streaming-daemon[1081]: # Volumio Streaming Daemon # Dec 05 21:06:11 volumio volumio-streaming-daemon[1081]: # Running on port 7777 # Dec 05 21:06:11 volumio volumio-streaming-daemon[1081]: ############################ Dec 05 21:06:11 volumio volumio[776]: info: Shairport-Sync Started Dec 05 21:06:11 volumio volumio[776]: Error adding Membership: Error: addMembership EINVAL Dec 05 21:06:11 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 21:06:11 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:12 volumio systemd[1]: Starting Music Player Daemon... Dec 05 21:06:12 volumio volumio[776]: info: Upmpdcli Daemon Started Dec 05 21:06:12 volumio volumio[776]: info: Shairport-Sync Started Dec 05 21:06:13 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:06:13 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:06:13 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:06:13 volumio sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:06:14 volumio sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:14 volumio sudo[1092]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:15 volumio volumio[776]: error: MyVolumio Custom Token format not valid, refreshing it Dec 05 21:06:17 volumio volumio[776]: info: Fetching Streaming Services browse cache Dec 05 21:06:18 volumio volumio[776]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesQOBUZ Dec 05 21:06:18 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:06:18 volumio volumio[776]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesTIDAL Dec 05 21:06:18 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:06:28 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:28 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:28 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:29 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:30 volumio volumio-streaming-daemon[1081]: Service tidal is not allowed Dec 05 21:06:31 volumio volumio[776]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 05 21:06:31 volumio volumio[776]: info: MYVOLUMIO: Adding device Dec 05 21:06:31 volumio volumio[776]: info: MYVOLUMIO: Evaluating Server Dec 05 21:06:37 volumio volumio[776]: info: [MyVolumio PluginManager] Subscribed plan changed to virtuoso Dec 05 21:06:37 volumio volumio[776]: info: Removing browser output: myVolumio user plan is not superstar Dec 05 21:06:37 volumio volumio[776]: info: Removing audio output: Dec 05 21:06:37 volumio volumio[776]: info: Setting Geolocation for MyVolumio to eu1 Dec 05 21:06:37 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:37 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:37 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:37 volumio volumio[776]: info: Remote config written successfully Dec 05 21:06:37 volumio volumio[776]: info: Starting Tunnel 1 Dec 05 21:06:37 volumio volumio[776]: info: Starting Tunnel Connection Checker Dec 05 21:06:38 volumio volumio[776]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 05 21:06:38 volumio volumio[776]: info: MyVolumio status changed Dec 05 21:06:38 volumio volumio[776]: info: Streaming services startup Dec 05 21:06:38 volumio volumio[776]: info: Re-Starting Streaming Daemon Dec 05 21:06:38 volumio sudo[1112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 05 21:06:38 volumio volumio[776]: info: Updating MyVolumio device info Dec 05 21:06:38 volumio sudo[1112]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:38 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:38 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:38 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 21:06:38 volumio systemd[1]: Starting MyVolumio SSH Tunnel... Dec 05 21:06:38 volumio systemd[1]: Started MyVolumio SSH Tunnel. Dec 05 21:06:38 volumio sudo[1112]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:38 volumio volumio-streaming-daemon[1081]: Restarting daemon Dec 05 21:06:39 volumio autossh[1118]: port set to 0, monitoring disabled Dec 05 21:06:39 volumio autossh[1118]: starting ssh (count 1) Dec 05 21:06:39 volumio autossh[1118]: ssh child pid is 1124 Dec 05 21:06:39 volumio volumio[776]: info: Remote SSH Started Dec 05 21:06:40 volumio volumiossh-tunnel[1117]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[188.166.162.121]:2222' (RSA) to the list of known hosts. Dec 05 21:06:40 volumio volumio-streaming-daemon[1081]: Enabled services: Dec 05 21:06:40 volumio volumio-streaming-daemon[1081]: 1) tidal Dec 05 21:06:40 volumio volumio-streaming-daemon[1081]: 2) qobuz Dec 05 21:06:43 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 05 21:06:43 volumio volumio[776]: error: [MyVolumio PluginManager] Cache data is invalid! Dec 05 21:06:46 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:06:46 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:06:46 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:06:47 volumio sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:06:47 volumio sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:47 volumio sudo[1127]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:47 volumio volumio[776]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 05 21:06:49 volumio volumio[776]: info: [1575580009030] Starting BluetoothController Dec 05 21:06:49 volumio volumio[776]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 05 21:06:50 volumio volumio[776]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 05 21:06:50 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 05 21:06:50 volumio volumio[776]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 05 21:06:50 volumio volumio[776]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Dec 05 21:06:50 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 05 21:06:50 volumio sudo[1141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Dec 05 21:06:50 volumio sudo[1141]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:50 volumio volumio[776]: info: Fetching Streaming Services browse cache Dec 05 21:06:51 volumio volumio[776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 05 21:06:51 volumio volumio[776]: info: [1575580011032] CoreMusicLibrary::Adding element TIDAL Dec 05 21:06:51 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:06:51 volumio kernel: Bluetooth: Core ver 2.22 Dec 05 21:06:51 volumio kernel: NET: Registered protocol family 31 Dec 05 21:06:51 volumio kernel: Bluetooth: HCI device and connection manager initialized Dec 05 21:06:51 volumio kernel: Bluetooth: HCI socket layer initialized Dec 05 21:06:51 volumio kernel: Bluetooth: L2CAP socket layer initialized Dec 05 21:06:51 volumio kernel: Bluetooth: SCO socket layer initialized Dec 05 21:06:51 volumio sudo[1141]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:51 volumio volumio[776]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesQOBUZ Dec 05 21:06:51 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:06:52 volumio volumio[776]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'Volumio' Dec 05 21:06:52 volumio volumio[776]: Can't get device info: No such device Dec 05 21:06:54 volumio sudo[1153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 05 21:06:54 volumio sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:54 volumio systemd[1]: Starting Volumio Bluetooth Module... Dec 05 21:06:54 volumio systemd[1]: Started Volumio Bluetooth Module. Dec 05 21:06:54 volumio sudo[1153]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:54 volumio sudo[1161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Dec 05 21:06:54 volumio sudo[1161]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:55 volumio volumiobt[1158]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Dec 05 21:06:55 volumio sudo[1161]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:56 volumio sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Dec 05 21:06:56 volumio sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:06:56 volumio volumiobt[1158]: pulseaudio: no process found Dec 05 21:06:57 volumio sudo[1171]: pam_unix(sudo:session): session closed for user root Dec 05 21:06:57 volumio volumio[776]: info: Volumio BT Module successfully started Dec 05 21:06:58 volumio dbus[601]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' Dec 05 21:06:58 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Dec 05 21:06:58 volumio volumio[776]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 05 21:06:58 volumio volumio[776]: BT PLUGIN MESSAGE: Playing: false Dec 05 21:06:58 volumio volumio[776]: BT PLUGIN MESSAGE: VOLATILE: Dec 05 21:06:58 volumio volumio[776]: BT PLUGIN MESSAGE: STATE:undefined Dec 05 21:06:58 volumio dbus[601]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Dec 05 21:06:58 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Successfully called chroot. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Successfully dropped privileges. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Successfully limited resources. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Running. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Watchdog thread running. Dec 05 21:06:58 volumio rtkit-daemon[1182]: Canary thread running. Dec 05 21:07:01 volumio dbus[601]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' Dec 05 21:07:01 volumio systemd[1]: Starting Bluetooth service... Dec 05 21:07:01 volumio volumio[776]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 05 21:07:01 volumio volumio[776]: BT PLUGIN MESSAGE: Playing: false Dec 05 21:07:01 volumio volumio[776]: BT PLUGIN MESSAGE: VOLATILE: Dec 05 21:07:01 volumio volumio[776]: BT PLUGIN MESSAGE: STATE:undefined Dec 05 21:07:01 volumio bluetoothd[1186]: Bluetooth daemon 5.23 Dec 05 21:07:01 volumio dbus[601]: [system] Successfully activated service 'org.bluez' Dec 05 21:07:02 volumio systemd[1]: Started Bluetooth service. Dec 05 21:07:02 volumio bluetoothd[1186]: Starting SDP server Dec 05 21:07:02 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Dec 05 21:07:02 volumio kernel: Bluetooth: BNEP filters: protocol multicast Dec 05 21:07:02 volumio kernel: Bluetooth: BNEP socket layer initialized Dec 05 21:07:02 volumio dbus[601]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' Dec 05 21:07:02 volumio bluetoothd[1186]: Bluetooth management interface 1.14 initialized Dec 05 21:07:02 volumio systemd[1]: Starting Hostname Service... Dec 05 21:07:02 volumio pulseaudio[1181]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 05 21:07:02 volumio pulseaudio[1181]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 05 21:07:02 volumio volumiobt[1158]: Applying permissions Dec 05 21:07:02 volumio volumiobt[1158]: Setting BT discoverable and pairable Dec 05 21:07:02 volumio pulseaudio[1181]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist Dec 05 21:07:02 volumio pulseaudio[1181]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist Dec 05 21:07:03 volumio volumiobt[1158]: [38B blob data] Dec 05 21:07:03 volumio volumiobt[1158]: Invalid command Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# agent on Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# discoverable on Dec 05 21:07:03 volumio volumiobt[1158]: No default controller available Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# pairable on Dec 05 21:07:03 volumio volumiobt[1158]: No default controller available Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# agent NoInputNoOutput Dec 05 21:07:03 volumio volumiobt[1158]: Failed to register agent object Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# default-agent Dec 05 21:07:03 volumio volumiobt[1158]: No agent is registered Dec 05 21:07:03 volumio volumiobt[1158]: [bluetooth]# quit Dec 05 21:07:03 volumio dbus[601]: [system] Successfully activated service 'org.freedesktop.hostname1' Dec 05 21:07:03 volumio systemd-hostnamed[1189]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname! Dec 05 21:07:03 volumio volumiobt[1158]: [61B blob data] Dec 05 21:07:03 volumio volumiobt[1158]: [62B blob data] Dec 05 21:07:06 volumio systemd[1]: Started Hostname Service. Dec 05 21:07:06 volumio volumio[776]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 05 21:07:06 volumio volumio[776]: BT PLUGIN MESSAGE: Playing: false Dec 05 21:07:06 volumio volumio[776]: BT PLUGIN MESSAGE: VOLATILE: Dec 05 21:07:06 volumio volumio[776]: BT PLUGIN MESSAGE: STATE:undefined Dec 05 21:07:42 volumio systemd[1]: mpd.service start operation timed out. Terminating. Dec 05 21:07:47 volumio sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:07:48 volumio sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:07:48 volumio sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:07:48 volumio sudo[1201]: pam_unix(sudo:session): session closed for user root Dec 05 21:07:48 volumio sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:07:48 volumio sudo[1203]: pam_unix(sudo:session): session closed for user root Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:07:49 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:07:49 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:07:49 volumio sudo[1221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:07:49 volumio sudo[1221]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:07:49 volumio sudo[1221]: pam_unix(sudo:session): session closed for user root Dec 05 21:07:49 volumio volumio[776]: info: Listing playlists Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 05 21:07:49 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 05 21:07:49 volumio sudo[1225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:07:49 volumio sudo[1225]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:07:50 volumio sudo[1225]: pam_unix(sudo:session): session closed for user root Dec 05 21:07:52 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 21:08:07 volumio volumio[776]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:08:07 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:08:07 volumio volumio[776]: info: CoreCommandRouter::volumioGetQueue Dec 05 21:08:07 volumio volumio[776]: info: CoreStateMachine::getQueue Dec 05 21:08:07 volumio volumio[776]: info: CorePlayQueue::getQueue Dec 05 21:08:07 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:08 volumio volumio[776]: info: No input data Dec 05 21:08:09 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:08:09 volumio volumio[776]: info: No input data Dec 05 21:08:09 volumio volumio[776]: info: No input data Dec 05 21:08:09 volumio volumio[776]: info: No input data Dec 05 21:08:09 volumio volumio[776]: info: No input data Dec 05 21:08:09 volumio volumio[776]: info: No input data Dec 05 21:08:11 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:08:12 volumio volumio[776]: info: No input data Dec 05 21:08:19 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:08:28 volumio volumio[776]: info: CoreCommandRouter::volumioAddQueueItems Dec 05 21:08:28 volumio volumio[776]: info: CoreStateMachine::addQueueItems Dec 05 21:08:28 volumio volumio[776]: info: CorePlayQueue::addQueueItems Dec 05 21:08:28 volumio volumio[776]: info: Adding Item to queue: tidal://playlist/1b64d985-0b32-40b9-b5d0-f415436d18be Dec 05 21:08:28 volumio volumio[776]: info: Exploding uri tidal://playlist/1b64d985-0b32-40b9-b5d0-f415436d18be in service streaming_services Dec 05 21:08:32 volumio volumio[776]: info: CorePlayQueue::saveQueue Dec 05 21:08:32 volumio volumio[776]: info: CoreCommandRouter::volumioPushQueue Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::updateTrackBlock Dec 05 21:08:32 volumio volumio[776]: info: CorePlayQueue::getTrackBlock Dec 05 21:08:32 volumio volumio[776]: info: CoreCommandRouter::volumioPlay Dec 05 21:08:32 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::play index 16 Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::stop Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:32 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::play index undefined Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:32 volumio volumio[776]: info: CorePlayQueue::getTrack 16 Dec 05 21:08:32 volumio volumio[776]: info: CoreStateMachine::startPlaybackTimer Dec 05 21:08:32 volumio volumio[776]: info: CorePlayQueue::getTrack 16 Dec 05 21:08:32 volumio volumio[776]: info: [1575580112945] streamingServices::clearAddPlayTrack Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: Loading tidal configuration Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: http://api.tidal.com/v1/tracks/47205339/streamurl?countryCode=DE&soundQuality=LOSSLESS Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: {"url":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMDNjNzMxMTQ0OTU4M2M5ZWEyM2I2NjY0ZGQ4OTdmZjRfNjEubXA0/0.flac?token=1575583713~MjRlNThhMTYyNTQ0NzU0MzJkNjUwZDNmOTI4NTE5OGQzOWQwZGIyOQ==","trackId":47205339,"playTimeLeftInMinutes":-1,"soundQuality":"LOSSLESS","encryptionKey":"","codec":"FLAC"} Dec 05 21:08:33 volumio volumio[776]: info: ControllerMpd::sendMpdCommand stop Dec 05 21:08:33 volumio volumio[776]: info: Got an error in getStreamUrl, asking volumio for next track Dec 05 21:08:33 volumio volumio[776]: info: CoreCommandRouter::volumioNext Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::next Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::stop Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:33 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::play index undefined Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:33 volumio volumio[776]: info: CorePlayQueue::getTrack 17 Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::startPlaybackTimer Dec 05 21:08:33 volumio volumio[776]: info: CorePlayQueue::getTrack 17 Dec 05 21:08:33 volumio volumio[776]: info: [1575580113529] streamingServices::clearAddPlayTrack Dec 05 21:08:33 volumio volumio[776]: info: CoreStateMachine::updateTrackBlock Dec 05 21:08:33 volumio volumio[776]: info: CorePlayQueue::getTrackBlock Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: Loading tidal configuration Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: http://api.tidal.com/v1/tracks/47205340/streamurl?countryCode=DE&soundQuality=LOSSLESS Dec 05 21:08:33 volumio volumio-streaming-daemon[1081]: {"url":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInYmY1M2I1OTI3NWRkMzBhYTI4Y2EyYzJkMjNkYzNjODRfNjEubXA0/0.flac?token=1575583713~OWNmZjUyOTYwMmEwNTNkOTQyZmE1MWI0NTMyMTgxMGU4Y2IzZDc4OQ==","trackId":47205340,"playTimeLeftInMinutes":-1,"soundQuality":"LOSSLESS","encryptionKey":"","codec":"FLAC"} Dec 05 21:08:33 volumio volumio[776]: info: ControllerMpd::sendMpdCommand stop Dec 05 21:08:33 volumio volumio[776]: info: Got an error in getStreamUrl, asking volumio for next track Dec 05 21:08:33 volumio volumio[776]: info: CoreCommandRouter::volumioNext Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::next Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::stop Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:34 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::play index undefined Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrack 18 Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::startPlaybackTimer Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrack 18 Dec 05 21:08:34 volumio volumio[776]: info: [1575580114104] streamingServices::clearAddPlayTrack Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::updateTrackBlock Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrackBlock Dec 05 21:08:34 volumio volumio-streaming-daemon[1081]: Loading tidal configuration Dec 05 21:08:34 volumio volumio-streaming-daemon[1081]: http://api.tidal.com/v1/tracks/47205342/streamurl?countryCode=DE&soundQuality=LOSSLESS Dec 05 21:08:34 volumio volumio-streaming-daemon[1081]: {"url":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInNGJjZTY0NTcwOTYwYjg2MzYzMjZiY2IzYTA5YzdiZDFfNjEubXA0/0.flac?token=1575583714~OWI2NGE4MTI3MDBlY2U1NDEwNmM0OGNkOWJmZTZkMzQwNDFiNzJkNw==","trackId":47205342,"playTimeLeftInMinutes":-1,"soundQuality":"LOSSLESS","encryptionKey":"","codec":"FLAC"} Dec 05 21:08:34 volumio volumio[776]: info: ControllerMpd::sendMpdCommand stop Dec 05 21:08:34 volumio volumio[776]: info: Got an error in getStreamUrl, asking volumio for next track Dec 05 21:08:34 volumio volumio[776]: info: CoreCommandRouter::volumioNext Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::next Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::stop Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:34 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::play index undefined Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrack 19 Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::startPlaybackTimer Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrack 19 Dec 05 21:08:34 volumio volumio[776]: info: [1575580114648] streamingServices::clearAddPlayTrack Dec 05 21:08:34 volumio volumio[776]: info: CoreStateMachine::updateTrackBlock Dec 05 21:08:34 volumio volumio[776]: info: CorePlayQueue::getTrackBlock Dec 05 21:08:34 volumio volumio-streaming-daemon[1081]: Loading tidal configuration Dec 05 21:08:34 volumio volumio-streaming-daemon[1081]: http://api.tidal.com/v1/tracks/47205346/streamurl?countryCode=DE&soundQuality=LOSSLESS Dec 05 21:08:35 volumio volumio-streaming-daemon[1081]: {"url":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInNTAxNDUzNWZjY2RjNWZjMmVhZmZkMDczN2NkYzdiZjBfNjEubXA0/0.flac?token=1575583715~NzlkMzA3MzU0NmVkNjcxNWQ2NjNiNDE5ODA4ZmFhYTM3YTU3YWVlMg==","trackId":47205346,"playTimeLeftInMinutes":-1,"soundQuality":"LOSSLESS","encryptionKey":"","codec":"FLAC"} Dec 05 21:08:35 volumio volumio[776]: info: ControllerMpd::sendMpdCommand stop Dec 05 21:08:35 volumio volumio[776]: info: Got an error in getStreamUrl, asking volumio for next track Dec 05 21:08:35 volumio volumio[776]: info: CoreCommandRouter::volumioNext Dec 05 21:08:35 volumio volumio[776]: info: CoreStateMachine::next Dec 05 21:08:35 volumio volumio[776]: info: CoreStateMachine::stop Dec 05 21:08:35 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:35 volumio volumio[776]: UNSET VOLATILE Dec 05 21:08:35 volumio volumio[776]: info: CoreStateMachine::play index undefined Dec 05 21:08:35 volumio volumio[776]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 05 21:08:35 volumio volumio[776]: info: CorePlayQueue::getTrack 20 Dec 05 21:09:12 volumio systemd[1]: mpd.service stop-final-sigterm timed out. Killing. Dec 05 21:09:12 volumio systemd[1]: mpd.service: main process exited, code=killed, status=9/KILL Dec 05 21:09:12 volumio systemd[1]: Failed to start Music Player Daemon. Dec 05 21:09:12 volumio systemd[1]: Unit mpd.service entered failed state. Dec 05 21:09:12 volumio systemd[1]: Starting Music Player Daemon... Dec 05 21:09:13 volumio volumio[776]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 05 21:09:13 volumio volumio[776]: BT PLUGIN MESSAGE: Playing: false Dec 05 21:09:13 volumio volumio[776]: BT PLUGIN MESSAGE: VOLATILE: undefined Dec 05 21:09:13 volumio volumio[776]: BT PLUGIN MESSAGE: STATE:undefined Dec 05 21:10:43 volumio systemd[1]: mpd.service start operation timed out. Terminating. Dec 05 21:11:07 volumio volumio[776]: info: CorePlayQueue::getTrack 0 Dec 05 21:11:07 volumio volumio[776]: info: CorePlayQueue::getTrack 1 Dec 05 21:11:07 volumio volumio[776]: info: Prefetching next song Dec 05 21:11:07 volumio volumio[776]: info: Doing prefetch in Streaming Services Dec 05 21:11:07 volumio volumio-streaming-daemon[1081]: Loading tidal configuration Dec 05 21:11:07 volumio volumio-streaming-daemon[1081]: http://api.tidal.com/v1/tracks/107809513/streamurl?countryCode=DE&soundQuality=LOSSLESS Dec 05 21:11:08 volumio volumio-streaming-daemon[1081]: {"url":"http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZGYxMjIzMThkNWQ4OWUxNWM0MTM1NzI2MzRhMjkyMGNfNjEubXA0/0.flac?token=1575583868~MmEzYjk5ZWRmYzExMGY5OTNkNDk4ZDhmMGQ0MTE3M2JjN2MxMTUzYw==","trackId":107809513,"playTimeLeftInMinutes":-1,"soundQuality":"LOSSLESS","encryptionKey":"","codec":"FLAC"} Dec 05 21:11:08 volumio volumio[776]: info: ControllerMpd::sendMpdCommand load "http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInZGYxMjIzMThkNWQ4OWUxNWM0MTM1NzI2MzRhMjkyMGNfNjEubXA0/0.flac?token=1575583868~MmEzYjk5ZWRmYzExMGY5OTNkNDk4ZDhmMGQ0MTE3M2JjN2MxMTUzYw==" Dec 05 21:11:08 volumio volumio[776]: error: Cannot prefetch Streaming Service track: TypeError: Cannot read property 'then' of undefined Dec 05 21:11:12 volumio volumio[776]: info: CoreStateMachine::startPlaybackTimer Dec 05 21:11:12 volumio volumio[776]: info: CorePlayQueue::getTrack 1 Dec 05 21:11:27 volumio volumio[776]: error: Upnp client error: Error: connect ETIMEDOUT 127.0.0.1:6600 Dec 05 21:12:09 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:12:09 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:12:09 volumio volumio[776]: info: CorePlayQueue::getTrack 1 Dec 05 21:12:09 volumio volumio[776]: info: CoreCommandRouter::volumioGetQueue Dec 05 21:12:09 volumio volumio[776]: info: CoreStateMachine::getQueue Dec 05 21:12:09 volumio volumio[776]: info: CorePlayQueue::getQueue Dec 05 21:12:09 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Dec 05 21:12:10 volumio sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:12:10 volumio sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:12:10 volumio sudo[1266]: pam_unix(sudo:session): session closed for user root Dec 05 21:12:13 volumio systemd[1]: mpd.service stop-final-sigterm timed out. Killing. Dec 05 21:12:13 volumio systemd[1]: mpd.service: main process exited, code=killed, status=9/KILL Dec 05 21:12:13 volumio systemd[1]: Failed to start Music Player Daemon. Dec 05 21:12:13 volumio systemd[1]: Unit mpd.service entered failed state. Dec 05 21:12:13 volumio systemd[1]: Starting Music Player Daemon... Dec 05 21:12:13 volumio volumio[776]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 05 21:12:13 volumio volumio[776]: BT PLUGIN MESSAGE: Playing: false Dec 05 21:12:13 volumio volumio[776]: BT PLUGIN MESSAGE: VOLATILE: undefined Dec 05 21:12:13 volumio volumio[776]: BT PLUGIN MESSAGE: STATE:undefined Dec 05 21:13:06 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:13:06 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:13:06 volumio volumio[776]: info: CorePlayQueue::getTrack 1 Dec 05 21:13:06 volumio volumio[776]: info: CoreCommandRouter::volumioGetQueue Dec 05 21:13:06 volumio volumio[776]: info: CoreStateMachine::getQueue Dec 05 21:13:06 volumio volumio[776]: info: CorePlayQueue::getQueue Dec 05 21:13:06 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Dec 05 21:13:06 volumio sudo[1287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:13:06 volumio sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:13:06 volumio sudo[1287]: pam_unix(sudo:session): session closed for user root Dec 05 21:13:11 volumio sudo[1298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 05 21:13:11 volumio sudo[1298]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:13:11 volumio sudo[1300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:13:11 volumio sudo[1298]: pam_unix(sudo:session): session closed for user root Dec 05 21:13:11 volumio sudo[1300]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:13:12 volumio sudo[1300]: pam_unix(sudo:session): session closed for user root Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::volumioGetVisibleSources Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::volumioGetState Dec 05 21:13:12 volumio volumio[776]: info: CoreStateMachine::getState Dec 05 21:13:12 volumio volumio[776]: info: CorePlayQueue::getTrack 1 Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 05 21:13:12 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 05 21:13:13 volumio sudo[1318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:13:13 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 05 21:13:13 volumio volumio[776]: info: Listing playlists Dec 05 21:13:13 volumio sudo[1318]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:13:13 volumio sudo[1318]: pam_unix(sudo:session): session closed for user root Dec 05 21:13:13 volumio sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 05 21:13:13 volumio sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:13:13 volumio sudo[1322]: pam_unix(sudo:session): session closed for user root Dec 05 21:13:15 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 05 21:13:16 volumio volumio[776]: info: CoreCommandRouter::volumioGetQueue Dec 05 21:13:16 volumio volumio[776]: info: CoreStateMachine::getQueue Dec 05 21:13:16 volumio volumio[776]: info: CorePlayQueue::getQueue Dec 05 21:13:16 volumio volumio[776]: info: No input data Dec 05 21:13:17 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:13:17 volumio volumio[776]: info: No input data Dec 05 21:13:19 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:13:21 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: streaming_services , handleBrowseUri Dec 05 21:13:26 volumio volumio[776]: info: No input data Dec 05 21:13:33 volumio volumio[776]: info: CoreCommandRouter::volumioAddQueueItems Dec 05 21:13:33 volumio volumio[776]: info: CoreStateMachine::addQueueItems Dec 05 21:13:33 volumio volumio[776]: info: CorePlayQueue::addQueueItems Dec 05 21:13:33 volumio volumio[776]: info: Adding Item to queue: tidal://playlist/fa0d0a1f-82cf-45e6-acd7-8d63f5c9abeb Dec 05 21:13:33 volumio volumio[776]: info: Exploding uri tidal://playlist/fa0d0a1f-82cf-45e6-acd7-8d63f5c9abeb in service streaming_services Dec 05 21:13:43 volumio systemd[1]: mpd.service start operation timed out. Terminating. Dec 05 21:13:52 volumio volumio[776]: info: An error occurred while exploding URI: TypeError: Cannot read property 'samplerate' of null Dec 05 21:13:57 volumio volumio[776]: error: Upnp client error: Error: connect ETIMEDOUT 127.0.0.1:6600 Dec 05 21:15:01 volumio volumio[776]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Dec 05 21:15:01 volumio volumio[776]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Dec 05 21:15:04 volumio sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Dec 05 21:15:05 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 05 21:15:05 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root Dec 05 21:15:06 volumio sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Dec 05 21:15:06 volumio sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) # cat /var/log/mpd.log --------------- Dec 05 21:06 : zeroconf: No global port, disabling zeroconf Dec 05 21:09 : zeroconf: No global port, disabling zeroconf Dec 05 21:12 : zeroconf: No global port, disabling zeroconf