Sat Nov 11 11:26:32 CET 2023 Description="'Spotify Connect does not work when a radio station is playing, but it does work after stopping the radio.'" # cat /proc/version --------------- Linux version 6.1.58-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1690 SMP Tue Oct 17 15:35:01 BST 2023 # cat /etc/os-release --------------- PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="893d2e91c55a7857b58762e70c2f65b9d163562b" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="30b77d58bf3c2745acc494ddafed946392a79905" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Oct 2023 03:38:28 PM CEST" VOLUMIO_VERSION="3.569" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4163d3756b55b3bf7c480d7285f68954" # ifconfig --------------- eth0: flags=4163 mtu 1500 inet 192.168.2.9 netmask 255.255.255.0 broadcast 192.168.2.255 ether b8:27:eb:ef:86:2f txqueuelen 1000 (Ethernet) RX packets 19139 bytes 19552331 (18.6 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 10924 bytes 4183191 (3.9 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73 mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 loop txqueuelen 1000 (Local Loopback) RX packets 3500 bytes 929171 (907.3 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 3500 bytes 929171 (907.3 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163 mtu 1500 inet 192.168.211.1 netmask 255.255.255.0 broadcast 192.168.211.255 ether b8:27:eb:ba:d3:7a txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 101 bytes 18167 (17.7 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 # sudo iwconfig --------------- lo no wireless extensions. eth0 no wireless extensions. wlan0 IEEE 802.11 Mode:Master Tx-Power=31 dBm Retry short limit:7 RTS thr:off Fragment thr:off Power Management:off # aplay -l --------------- **** List of PLAYBACK Hardware Devices **** card 0: b1 [bcm2835 HDMI 1], device 0: bcm2835 HDMI 1 [bcm2835 HDMI 1] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 0: b1 [bcm2835 HDMI 1], device 1: bcm2835 HDMI 1 [bcm2835 HDMI 1] Subdevices: 1/1 Subdevice #0: subdevice #0 card 1: Headphones [bcm2835 Headphones], device 0: bcm2835 Headphones [bcm2835 Headphones] Subdevices: 4/4 Subdevice #0: subdevice #0 Subdevice #1: subdevice #1 Subdevice #2: subdevice #2 Subdevice #3: subdevice #3 card 2: sndrpihifiberry [snd_rpi_hifiberry_dacplus], device 0: HiFiBerry DAC+ Pro HiFi pcm512x-hifi-0 [HiFiBerry DAC+ Pro HiFi pcm512x-hifi-0] Subdevices: 0/1 Subdevice #0: subdevice #0 # lsusb --------------- Bus 001 Device 004: ID 0712:0009 Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub # lsusb -t --------------- /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/5p, 480M |__ Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=smsc95xx, 480M |__ Port 3: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 12M # lsusb -v --------------- Couldn't open device, some information will be missing Couldn't open device, some information will be missing Bus 001 Device 004: ID 0712:0009 Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 0 bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 64 idVendor 0x0712 idProduct 0x0009 bcdDevice 2.00 iManufacturer 1 iProduct 2 iSerial 3 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0022 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0x80 (Bus Powered) MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 3 Human Interface Device bInterfaceSubClass 0 bInterfaceProtocol 2 Mouse iInterface 0 HID Device Descriptor: bLength 9 bDescriptorType 33 bcdHID 1.11 bCountryCode 0 Not supported bNumDescriptors 1 bDescriptorType 34 Report wDescriptorLength 735 Report Descriptors: ** UNAVAILABLE ** Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0040 1x 64 bytes bInterval 10 Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 255 Vendor Specific Class bDeviceSubClass 0 bDeviceProtocol 1 bMaxPacketSize0 64 idVendor 0x0424 Standard Microsystems Corp. idProduct 0xec00 SMSC9512/9514 Fast Ethernet Adapter bcdDevice 2.00 iManufacturer 0 iProduct 0 iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0027 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 2mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 3 bInterfaceClass 255 Vendor Specific Class bInterfaceSubClass 0 bInterfaceProtocol 255 iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x02 EP 2 OUT bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x83 EP 3 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Couldn't open device, some information will be missing Couldn't open device, some information will be missing Usage Type Data wMaxPacketSize 0x0010 1x 16 bytes bInterval 4 Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 2 TT per port bMaxPacketSize0 64 idVendor 0x0424 Standard Microsystems Corp. idProduct 0x9514 SMC9514 Hub bcdDevice 2.00 iManufacturer 0 iProduct 0 iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0029 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 2mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 1 Single TT iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0001 1x 1 bytes bInterval 12 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 1 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 2 TT per port iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0001 1x 1 bytes bInterval 12 Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 1 Single TT bMaxPacketSize0 64 idVendor 0x1d6b Linux Foundation idProduct 0x0002 2.0 root hub bcdDevice 6.01 iManufacturer 3 iProduct 2 iSerial 1 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0019 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 12 # ps -ef --------------- UID PID PPID C STIME TTY TIME CMD root 1 0 1 11:17 ? 00:00:07 /sbin/init root 2 0 0 11:17 ? 00:00:00 [kthreadd] root 3 2 0 11:17 ? 00:00:00 [rcu_gp] root 4 2 0 11:17 ? 00:00:00 [rcu_par_gp] root 5 2 0 11:17 ? 00:00:00 [slub_flushwq] root 6 2 0 11:17 ? 00:00:00 [netns] root 10 2 0 11:17 ? 00:00:00 [mm_percpu_wq] root 11 2 0 11:17 ? 00:00:00 [rcu_tasks_rude_kthread] root 12 2 0 11:17 ? 00:00:00 [rcu_tasks_trace_kthread] root 13 2 0 11:17 ? 00:00:00 [ksoftirqd/0] root 14 2 0 11:17 ? 00:00:00 [rcu_sched] root 15 2 0 11:17 ? 00:00:00 [migration/0] root 16 2 0 11:17 ? 00:00:00 [cpuhp/0] root 17 2 0 11:17 ? 00:00:00 [cpuhp/1] root 18 2 0 11:17 ? 00:00:01 [migration/1] root 19 2 0 11:17 ? 00:00:00 [ksoftirqd/1] root 22 2 0 11:17 ? 00:00:00 [cpuhp/2] root 23 2 0 11:17 ? 00:00:01 [migration/2] root 24 2 0 11:17 ? 00:00:00 [ksoftirqd/2] root 27 2 0 11:17 ? 00:00:00 [cpuhp/3] root 28 2 0 11:17 ? 00:00:01 [migration/3] root 29 2 0 11:17 ? 00:00:00 [ksoftirqd/3] root 32 2 0 11:17 ? 00:00:00 [kdevtmpfs] root 33 2 0 11:17 ? 00:00:00 [inet_frag_wq] root 35 2 0 11:17 ? 00:00:00 [kauditd] root 36 2 0 11:17 ? 00:00:00 [khungtaskd] root 37 2 0 11:17 ? 00:00:00 [kworker/u8:1-events_unbound] root 38 2 0 11:17 ? 00:00:00 [oom_reaper] root 39 2 0 11:17 ? 00:00:00 [writeback] root 40 2 0 11:17 ? 00:00:00 [kcompactd0] root 41 2 0 11:17 ? 00:00:00 [kintegrityd] root 42 2 0 11:17 ? 00:00:00 [kblockd] root 43 2 0 11:17 ? 00:00:00 [blkcg_punt_bio] root 44 2 0 11:17 ? 00:00:00 [watchdogd] root 45 2 0 11:17 ? 00:00:00 [kworker/1:1-mm_percpu_wq] root 48 2 0 11:17 ? 00:00:00 [kworker/2:1H-kblockd] root 49 2 0 11:17 ? 00:00:00 [rpciod] root 50 2 0 11:17 ? 00:00:00 [xprtiod] root 51 2 0 11:17 ? 00:00:00 [kworker/u8:3-loop0] root 52 2 0 11:17 ? 00:00:00 [kswapd0] root 53 2 0 11:17 ? 00:00:00 [nfsiod] root 58 2 0 11:17 ? 00:00:00 [hwrng] root 60 2 0 11:17 ? 00:00:00 [iscsi_conn_clea] root 61 2 0 11:17 ? 00:00:00 [dwc_otg] root 62 2 0 11:17 ? 00:00:00 [DWC Notificatio] root 63 2 0 11:17 ? 00:00:00 [vchiq-slot/0] root 64 2 0 11:17 ? 00:00:00 [vchiq-recy/0] root 65 2 0 11:17 ? 00:00:00 [vchiq-sync/0] root 66 2 0 11:17 ? 00:00:00 [zswap-shrink] root 67 2 0 11:17 ? 00:00:00 [kworker/u9:0-brcmf_wq/mmc1:0001:1] root 88 2 0 11:17 ? 00:00:00 [kworker/0:3-events] root 89 2 0 11:17 ? 00:00:00 [mmc_complete] root 90 2 0 11:17 ? 00:00:00 [kworker/0:1H-mmc_complete] root 98 2 0 11:17 ? 00:00:00 [kworker/3:1H-kblockd] root 119 2 0 11:17 ? 00:00:00 [kworker/0:2H-kblockd] root 120 2 0 11:17 ? 00:00:00 [kworker/1:1H-kblockd] root 121 2 0 11:17 ? 00:00:00 [kworker/1:2H-kblockd] root 125 2 0 11:17 ? 00:00:00 [jbd2/mmcblk0p2-8] root 126 2 0 11:17 ? 00:00:00 [ext4-rsv-conver] root 130 2 0 11:17 ? 00:00:00 [irq/199-usb-001:003:01] root 161 2 0 11:17 ? 00:00:00 [kworker/2:2H-kblockd] root 162 2 0 11:17 ? 00:00:00 [jbd2/mmcblk0p3-8] root 163 2 0 11:17 ? 00:00:00 [ext4-rsv-conver] root 171 2 0 11:17 ? 00:00:00 [mld] root 172 2 0 11:17 ? 00:00:00 [ipv6_addrconf] root 206 1 0 11:17 ? 00:00:01 /lib/systemd/systemd-journald root 222 2 0 11:17 ? 00:00:00 [kworker/3:5-cgroup_destroy] root 225 2 0 11:17 ? 00:00:00 [kworker/3:8-events] root 229 1 0 11:17 ? 00:00:01 /lib/systemd/systemd-udevd root 245 2 0 11:17 ? 00:00:00 [kworker/2:3-events] root 250 2 0 11:17 ? 00:00:00 [kworker/3:2H-kblockd] root 266 2 0 11:17 ? 00:00:00 [vchiq-keep/0] root 267 2 0 11:17 ? 00:00:00 [SMIO] root 307 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 310 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 312 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 313 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 315 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 316 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 317 2 0 11:17 ? 00:00:00 [mmal-vchiq] root 351 2 0 11:17 ? 00:00:00 [kworker/u9:1-hci0] root 366 2 0 11:17 ? 00:00:00 [cfg80211] root 384 2 0 11:17 ? 00:00:00 [brcmf_wq/mmc1:0] root 385 2 0 11:17 ? 00:00:00 [brcmf_wdog/mmc1:0001:1] _rpc 475 1 0 11:17 ? 00:00:00 /sbin/rpcbind -f -w root 481 1 0 11:17 ? 00:00:02 /usr/sbin/haveged --Foreground --verbose=1 -w 1024 root 523 1 0 11:17 ? 00:00:00 /usr/sbin/alsactl -E HOME=/run/alsa -s -n 19 -c rdaemon nobody 524 1 0 11:17 ? 00:00:00 /usr/sbin/thd --triggers /etc/triggerhappy/triggers.d/ --socket /run/thd.socket --user nobody --deviceglob /dev/input/event* root 529 1 0 11:17 ? 00:00:00 /lib/systemd/systemd-logind message+ 530 1 0 11:17 ? 00:00:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only root 537 1 0 11:17 ? 00:00:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant volumio 538 1 0 11:17 ? 00:00:00 /usr/local/bin/volumio-remote-updater avahi 542 1 0 11:17 ? 00:00:00 avahi-daemon: running [volumio.local] avahi 588 542 0 11:17 ? 00:00:00 avahi-daemon: chroot helper root 642 1 0 11:18 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 650 2 0 11:18 ? 00:00:00 [kworker/1:5-mm_percpu_wq] ntp 656 1 0 11:18 ? 00:00:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 root 660 1 0 11:18 ? 00:00:00 /usr/sbin/sshd -D root 672 1 0 11:18 ? 00:00:00 /usr/sbin/ifplugd -i eth0 -q -f -u0 -d10 -w -I root 674 1 0 11:18 tty1 00:00:00 /sbin/agetty -o -p -- \u --noclear tty1 linux root 676 1 0 11:18 ? 00:00:00 /usr/lib/bluetooth/bluetoothd --noplugin=sap root 701 642 0 11:18 ? 00:00:00 /usr/sbin/nmbd --foreground --no-process-group root 768 1 0 11:18 ? 00:00:00 /sbin/dhcpcd eth0 dnsmasq 796 1 0 11:18 ? 00:00:00 /usr/sbin/dnsmasq -x /run/dnsmasq/dnsmasq.pid -u dnsmasq -7 /etc/dnsmasq.d,.dpkg-dist,.dpkg-old,.dpkg-new --local-service root 805 1 0 11:18 ? 00:00:00 /usr/sbin/hostapd -B -P /run/hostapd.pid -B /etc/hostapd/hostapd.conf volumio 809 1 7 11:18 ? 00:00:37 /usr/bin/node /volumio/index.js root 833 1 0 11:18 ? 00:00:00 /usr/sbin/winbindd --foreground --no-process-group root 836 833 0 11:18 ? 00:00:00 winbindd: domain child [VOLUMIO] root 838 1 0 11:18 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 840 838 0 11:18 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 841 838 0 11:18 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group root 842 833 0 11:18 ? 00:00:00 winbindd: idmap child root 843 833 0 11:18 ? 00:00:00 winbindd: domain child [BUILTIN] root 852 838 0 11:18 ? 00:00:00 /usr/sbin/smbd --foreground --no-process-group volumio 885 809 0 11:18 ? 00:00:00 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 892 885 0 11:18 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 893 885 0 11:18 ? 00:00:02 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 894 885 0 11:18 ? 00:00:01 /usr/bin/node /volumio/app/plugins/miscellanea/albumart/serverStartup.js 3001 /data/albumart volumio 966 1 0 11:18 ? 00:00:00 /usr/bin/upmpdcli -c /tmp/upmpdcli.conf root 977 2 0 11:18 ? 00:00:00 [kworker/2:4-cgroup_destroy] root 1015 2 0 11:18 ? 00:00:00 [irq/201-rotary-encoder] root 1016 2 0 11:18 ? 00:00:00 [irq/202-rotary-encoder] volumio 1066 809 0 11:18 ? 00:00:00 /bin/cat /dev/input/by-path/platform-rotary@17-event volumio 1067 1 0 11:18 ? 00:00:00 /bin/sh /bin/start-go-liberspot.sh volumio 1075 1067 6 11:18 ? 00:00:31 /usr/bin/go-librespot -config_path /tmp/go-librespot-config.yml -credentials_path /data/configuration/music_service/spop/spotifycredentials.json volumio 1077 1 0 11:18 ? 00:00:00 /bin/sh /usr/bin/startx /etc/X11/Xsession /opt/volumiokiosk.sh volumio 1114 1077 0 11:18 ? 00:00:00 xinit /etc/X11/Xsession /opt/volumiokiosk.sh -- /etc/X11/xinit/xserverrc :0 -auth /tmp/serverauth.azOzUcAZUt root 1115 1114 0 11:18 tty2 00:00:02 /usr/lib/xorg/Xorg -nolisten tcp :0 -auth /tmp/serverauth.azOzUcAZUt mpd 1126 1 0 11:18 ? 00:00:02 /usr/bin/mpd --no-daemon volumio 1130 1 0 11:18 ? 00:00:02 /usr/bin/python3 /data/plugins/audio_interface/fusiondsp/cgui/main.py shairpo+ 1136 1 0 11:18 ? 00:00:00 /usr/bin/shairport-sync --configfile=/tmp/shairport-sync.conf root 1153 2 0 11:18 ? 00:00:00 [rc0] root 1165 1 0 11:18 ? 00:00:00 /usr/sbin/lircd --nodaemon root 1166 1165 0 11:18 ? 00:00:00 [sh] root 1177 1 0 11:18 ? 00:00:00 /usr/bin/irexec /etc/lirc/irexec.lircrc volumio 1203 1114 0 11:18 ? 00:00:00 /bin/bash /opt/volumiokiosk.sh volumio 1229 1203 0 11:18 ? 00:00:00 /usr/bin/ssh-agent /opt/volumiokiosk.sh volumio 1236 1203 0 11:18 ? 00:00:00 /usr/bin/openbox --startup /usr/lib/arm-linux-gnueabihf/openbox-autostart OPENBOX volumio 1237 1203 1 11:18 ? 00:00:05 /usr/lib/chromium-browser/chromium-browser-v7 --enable-pinch --simulate-outdated-no-au=Tue, 31 Dec 2099 23:59:59 GMT --force-device-scale-factor=1 --disable-pinch --kiosk --no-first-run --noerrdialogs --disable-3d-apis --disable-breakpad --disable-crash-reporter --disable-infobars --disable-session-crashed-bubble --disable-translate --user-data-dir=/data/volumiokiosk http://localhost:4004 volumio 1273 1 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/crashpad_handler --monitor-self --monitor-self-annotation=ptype=crashpad-handler --database=/home/volumio/.config/chromium/Crash Reports --metrics-dir=/data/volumiokiosk --annotation=channel=Built on Raspbian , running on Raspbian 10 --annotation=lsb-release=Raspbian GNU/Linux 10 (buster) --annotation=plat=Linux --annotation=prod=Chrome_Linux --annotation=ver=92.0.4515.98 --initial-client-fd=7 --shared-client-connection volumio 1275 1 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/crashpad_handler --no-periodic-tasks --monitor-self-annotation=ptype=crashpad-handler --database=/home/volumio/.config/chromium/Crash Reports --annotation=channel=Built on Raspbian , running on Raspbian 10 --annotation=lsb-release=Raspbian GNU/Linux 10 (buster) --annotation=plat=Linux --annotation=prod=Chrome_Linux --annotation=ver=92.0.4515.98 --initial-client-fd=4 --shared-client-connection volumio 1279 1237 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/chromium-browser-v7 --type=zygote --no-zygote-sandbox --force-device-scale-factor=1 --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --enable-crashpad volumio 1280 1237 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/chromium-browser-v7 --type=zygote --force-device-scale-factor=1 --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --enable-crashpad volumio 1282 1280 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/chromium-browser-v7 --type=zygote --force-device-scale-factor=1 --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --enable-crashpad volumio 1312 1237 0 11:18 ? 00:00:01 /usr/lib/chromium-browser/chromium-browser-v7 --type=utility --utility-sub-type=network.mojom.NetworkService --field-trial-handle=13536231999380929437,15217820135997225147,131072 --lang=en-US --service-sandbox-type=none --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --shared-files=v8_context_snapshot_data:100 --enable-crashpad volumio 1328 1279 0 11:18 ? 00:00:04 /usr/lib/chromium-browser/chromium-browser-v7 --type=gpu-process --field-trial-handle=13536231999380929437,15217820135997225147,131072 --disable-breakpad --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --gpu-preferences=UAAAAAAAAAAgAAAQAAAAAAAAAAAAAAAAAABgAAAAAAAwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAAANgAAAAAAAAA2AAAAAAAAABIAAAACAAAAEAAAAAAAAAASAAAAAAAAABQAAAAAAAAAFgAAAAAAAAAYAAAAAAAAABoAAAAAAAAAHAAAAAAAAAAeAAAAAAAAAAQAAAAAAAAAAAAAAAMAAAAEAAAAAAAAAAAAAAADQAAABAAAAAAAAAAAQAAAAwAAAAQAAAAAAAAAAEAAAANAAAAEAAAAAAAAAAEAAAADAAAABAAAAAAAAAABAAAAA0AAAAQAAAAAAAAAAcAAAAMAAAAEAAAAAAAAAAHAAAADQAAAAgAAAAAAAAACAAAAAAAAAA= --use-gl=swiftshader-webgl --shared-files volumio 1331 1328 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/chromium-browser-v7 --type=broker volumio 1338 1282 0 11:18 ? 00:00:00 /usr/lib/chromium-browser/chromium-browser-v7 --type=utility --utility-sub-type=storage.mojom.StorageService --field-trial-handle=13536231999380929437,15217820135997225147,131072 --lang=en-US --service-sandbox-type=utility --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --shared-files=v8_context_snapshot_data:100 volumio 1346 809 0 11:18 ? 00:00:01 /usr/bin/node /myvolumio/plugins/music_service/streaming_services/streamingProxy.js volumio 1371 1282 7 11:18 ? 00:00:35 /usr/lib/chromium-browser/chromium-browser-v7 --type=renderer --disable-breakpad --force-device-scale-factor=1 --field-trial-handle=13536231999380929437,15217820135997225147,131072 --disable-gpu-compositing --lang=en-US --enable-crashpad --crashpad-handler-pid=0 --enable-crash-reporter=,Built on Raspbian , running on Raspbian 10 --noerrdialogs --user-data-dir=/data/volumiokiosk --disable-3d-apis --origin-trial-disabled-features=WebGPU --num-raster-threads=2 --enable-main-frame-before-activation --renderer-client-id=6 --no-v8-untrusted-code-mitigations --shared-files=v8_context_snapshot_data:100 root 1711 2 0 11:19 ? 00:00:00 [kworker/0:5-events] volumio 1761 809 0 11:19 ? 00:00:00 /bin/journalctl --output cat -f root 1881 2 0 11:24 ? 00:00:00 [kworker/0:0-events] root 1882 2 0 11:24 ? 00:00:00 [kworker/1:0-mm_percpu_wq] root 1886 2 0 11:25 ? 00:00:00 [kworker/u8:0] volumio 1892 1 84 11:26 ? 00:00:26 /data/plugins/audio_interface/fusiondsp/camilladsp -p 9876 -l warn -o /tmp/camilladsp.log -r 44100 -f S32LE -n 2 /data/configuration/audio_interface/fusiondsp/camilladsp.yml volumio 1907 809 1 11:26 ? 00:00:00 /bin/sh -c /usr/bin/node /volumio/logsubmit.js 'Spotify Connect does not work when a radio station is playing, but it does work after stopping the radio.' volumio 1908 1907 50 11:26 ? 00:00:00 /usr/bin/node /volumio/logsubmit.js Spotify Connect does not work when a radio station is playing, but it does work after stopping the radio. volumio 1936 1908 0 11:26 ? 00:00:00 /bin/sh -c ps -ef >>/tmp/logondemand 2>&1 volumio 1937 1936 0 11:26 ? 00:00:00 ps -ef # df -h --------------- Filesystem Size Used Avail Use% Mounted on /dev/mmcblk0p2 2.5G 535M 1.8G 24% /imgpart /dev/loop0 470M 470M 0 100% /static overlay 27G 1.3G 24G 5% / devtmpfs 444M 0 444M 0% /dev tmpfs 483M 19M 465M 4% /dev/shm tmpfs 483M 5.3M 478M 2% /run tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 483M 0 483M 0% /sys/fs/cgroup tmpfs 20M 44K 20M 1% /var/log tmpfs 483M 1.2M 482M 1% /tmp tmpfs 483M 0 483M 0% /var/spool/cups tmpfs 483M 0 483M 0% /var/spool/cups/tmp /dev/mmcblk0p1 92M 66M 26M 73% /boot # mount --------------- /dev/mmcblk0p2 on /imgpart type ext4 (rw,relatime) /dev/loop0 on /static type squashfs (ro,relatime,errors=continue) 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=454476k,nr_inodes=113619,mode=755) securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev,noexec) devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k) tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755) cgroup2 on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate) cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd) pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime) bpf on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700) cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset) cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct) cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids) cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices) cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio) cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event) cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer) systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=32,pgrp=1,timeout=0,minproto=5,maxproto=5,direct) sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime) debugfs on /sys/kernel/debug type debugfs (rw,relatime) mqueue on /dev/mqueue type mqueue (rw,relatime) configfs on /sys/kernel/config type configfs (rw,relatime) tmpfs on /var/log type tmpfs (rw,nodev,relatime,size=20480k,mode=777,uid=1000,gid=4) tmpfs on /tmp type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups type tmpfs (rw,noatime,mode=755) tmpfs on /var/spool/cups/tmp type tmpfs (rw,noatime,mode=755) /dev/mmcblk0p1 on /boot type vfat (rw,nosuid,nodev,noexec,relatime,fmask=0111,dmask=0000,allow_utime=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,user) # netstat -natp --------------- (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 0.0.0.0:139 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:49152 0.0.0.0:* LISTEN 966/upmpdcli tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:53 0.0.0.0:* LISTEN - tcp 0 0 127.0.0.1:9876 0.0.0.0:* LISTEN 1892/camilladsp tcp 0 0 0.0.0.0:49149 0.0.0.0:* LISTEN 966/upmpdcli tcp 0 0 0.0.0.0:5000 0.0.0.0:* LISTEN - tcp 0 0 0.0.0.0:5011 0.0.0.0:* LISTEN 1130/python3 tcp 0 0 0.0.0.0:445 0.0.0.0:* LISTEN - tcp 0 0 127.0.0.1:9876 127.0.0.1:49718 ESTABLISHED 1892/camilladsp tcp 0 0 127.0.0.1:49718 127.0.0.1:9876 ESTABLISHED 809/node tcp 0 0 127.0.0.1:37504 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 127.0.0.1:51568 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 127.0.0.1:51668 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 127.0.0.1:51510 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 127.0.0.1:48622 127.0.0.1:3000 ESTABLISHED 538/volumio-remote- tcp 0 0 127.0.0.1:58406 127.0.0.1:6599 ESTABLISHED 966/upmpdcli tcp 0 0 192.168.2.9:49592 34.158.0.131:4070 ESTABLISHED 1075/go-librespot tcp 0 0 127.0.0.1:57122 127.0.0.1:9879 ESTABLISHED 809/node tcp 0 0 192.168.2.9:32930 104.109.143.21:443 ESTABLISHED 1075/go-librespot tcp 0 0 192.168.2.9:45488 199.232.150.208:443 ESTABLISHED 1312/volumiokiosk - tcp 0 0 127.0.0.1:57162 127.0.0.1:3000 ESTABLISHED 1312/volumiokiosk - tcp 1 0 192.168.2.9:57106 168.119.68.93:80 CLOSE_WAIT - tcp 0 0 192.168.2.9:37738 34.117.98.4:443 ESTABLISHED 1075/go-librespot tcp 0 0 192.168.2.9:52786 35.186.224.17:443 ESTABLISHED 1075/go-librespot tcp 130 0 192.168.2.9:54588 142.251.36.3:443 CLOSE_WAIT 1312/volumiokiosk - tcp 0 0 127.0.0.1:51582 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 127.0.0.1:58408 127.0.0.1:6599 ESTABLISHED 966/upmpdcli tcp 0 0 127.0.0.1:57116 127.0.0.1:3000 ESTABLISHED 809/node tcp 1 0 192.168.2.9:36800 3.230.175.211:80 CLOSE_WAIT - tcp 0 0 192.168.2.9:57230 104.109.143.27:443 ESTABLISHED 1075/go-librespot tcp 0 0 127.0.0.1:51490 127.0.0.1:3000 ESTABLISHED 809/node tcp 0 0 192.168.2.9:48924 34.120.160.131:443 ESTABLISHED 809/node tcp 0 0 192.168.2.9:41546 34.104.35.123:80 ESTABLISHED 1312/volumiokiosk - tcp6 0 0 :::139 :::* LISTEN - tcp6 0 0 :::9879 :::* LISTEN 1075/go-librespot tcp6 0 0 :::3245 :::* LISTEN 1346/node tcp6 0 0 :::111 :::* LISTEN - tcp6 0 0 :::22 :::* LISTEN - tcp6 0 0 :::53 :::* LISTEN - tcp6 0 0 :::6599 :::* LISTEN 809/node tcp6 0 0 :::6600 :::* LISTEN - tcp6 0 0 :::5000 :::* LISTEN - tcp6 0 0 :::4004 :::* LISTEN 809/node tcp6 0 0 :::3005 :::* LISTEN 809/node tcp6 0 0 :::445 :::* LISTEN - tcp6 0 0 :::3000 :::* LISTEN 809/node tcp6 0 0 :::3001 :::* LISTEN 885/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:57116 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:9879 127.0.0.1:57122 ESTABLISHED 1075/go-librespot tcp6 0 0 127.0.0.1:6599 127.0.0.1:58408 ESTABLISHED 809/node tcp6 0 0 192.168.2.9:3000 192.168.2.11:50553 FIN_WAIT2 - tcp6 0 0 127.0.0.1:3000 127.0.0.1:51582 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:51668 ESTABLISHED 809/node tcp6 0 0 192.168.2.9:3000 192.168.2.11:50555 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:51510 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:51490 ESTABLISHED 809/node tcp6 0 0 192.168.2.9:3000 192.168.2.11:50554 FIN_WAIT2 - tcp6 0 0 127.0.0.1:3000 127.0.0.1:57162 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:51568 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:6599 127.0.0.1:58406 ESTABLISHED 809/node tcp6 0 0 127.0.0.1:3000 127.0.0.1:48622 ESTABLISHED 809/node tcp6 0 0 192.168.2.9:3000 192.168.2.11:50552 FIN_WAIT2 - tcp6 0 0 127.0.0.1:3000 127.0.0.1:37504 ESTABLISHED 809/node # cat /etc/asound.conf --------------- pcm.!default { type empty slave.pcm "volumio" } pcm.volumio { type empty slave.pcm "volumioDsp" } #------ FusionDsp section ------- pcm.volumioDsp { type plug slave.pcm "fusiondsphook" } pcm.fusiondsphook { type volumiohook slave.pcm "fusiondspfifo" hw_params_command "echo %r >/tmp/sr.log && sleep 1.5 && /data/plugins/audio_interface/fusiondsp/camilladsp -p 9876 -l warn -o /tmp/camilladsp.log -r %r -f $(echo '%f' | sed 's/_//') -n 2 /data/configuration/audio_interface/fusiondsp/camilladsp.yml &" hw_free_command "tail --pid `pidof camilladsp` -f /dev/null" debug 1 } pcm.fusiondspfifo { type volumiofifo fifo "/tmp/fusiondspfifo" format_3 "S16_LE" format_4 "S24_LE" format_5 "S32_LE" clear_on_drop "false" } #------ End of FusionDsp section ------ pcm.postDsp { type empty slave.pcm "volumioOutput" } # There is always a plug before the hardware to be safe pcm.volumioOutput { type plug slave.pcm "volumioHw" } pcm.volumioHw { type hw card "sndrpihifiberry" } # cat /var/log/mpd.log --------------- Nov 10 17:01 : zeroconf: No global port, disabling zeroconf Nov 10 17:02 : zeroconf: No global port, disabling zeroconf Nov 10 17:02 : zeroconf: No global port, disabling zeroconf Nov 10 17:02 : zeroconf: No global port, disabling zeroconf Nov 11 11:20 : exception: No such playlist Nov 11 11:20 : player: played "http://mp3-128.streamthejazzgroove.com/?referer=tunein.com" ALSA lib /home/pi/volumio-hook-plugin/src/pcm_volumiohook.c:144:(snd_pcm_volumiohook_close) PCM close called for fusiondsphook # cat /tmp/camilladsp.log --------------- 2023-11-11 10:20:31.286430 ERROR [src/socketserver.rs:290] Failed to start websocket server: Address already in use (os error 98) 2023-11-11 10:20:31.329047 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy' # cat /tmp/cec-client.log --------------- cat: /tmp/cec-client.log: No such file or directory # volumio plugin list --------------- This command will list installed plugins on your device ----------------------- Installed Plugins: [ { prettyName: 'FusionDsp', name: 'fusiondsp', category: 'audio_interface', version: '1.0.49', icon: 'fa-sliders fa-rotate-90', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'MotherEarthRadio', name: 'motherearthradio', category: 'music_service', version: '1.2.2', icon: 'fa-lightbulb-o', isManuallyInstalled: false, enabled: false, active: false }, { prettyName: 'Spotify', name: 'spop', category: 'music_service', version: '4.0.3', icon: 'fa-spotify', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'GPIO Buttons', name: 'gpio-buttons', category: 'system_hardware', version: '0.8.3', icon: 'fa-microchip', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'IR Remote Controller', name: 'ir_controller', category: 'system_hardware', version: '3.4.11', icon: 'fa-magic', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'Rotary Encoder II', name: 'rotaryencoder2', category: 'system_hardware', version: '1.0.15', icon: 'fa-circle-o-notch', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'Now Playing', name: 'now_playing', category: 'user_interface', version: '0.5.4', icon: 'fa-play-circle', isManuallyInstalled: false, enabled: true, active: true }, { prettyName: 'Touch Display', name: 'touch_display', category: 'user_interface', version: '3.3.7', icon: 'fa-hand-pointer-o', isManuallyInstalled: false, enabled: true, active: true } ] ------------------------------------------ # cat /data/configuration/plugins.json --------------- { "music_service": { "airplay_emulation": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "inputs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "mpd": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "webradio": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "example_plugin": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STOPPED" } }, "last_100": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "upnp_browser": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "streaming_services": { "status": { "type": "string", "value": "STARTED" } }, "spop": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "motherearthradio": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STOPPED" } } }, "audio_interface": { "outputs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "upnp": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "alsa_controller": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "fusiondsp": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "miscellanea": { "alarm-clock": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "albumart": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "appearance": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "wizard": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "my_music": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "user_interface": { "websocket": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "mpdemulation": { "enabled": { "type": "boolean", "value": false }, "status": { "type": "string", "value": "STARTED" } }, "rest_api": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "touch_display": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "now_playing": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } }, "system_controller": { "updater_comm": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "network": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "networkfs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "services": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "system": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "i2s_dacs": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "volumiodiscovery": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "volumio_command_line_client": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "my_volumio": { "status": { "type": "string", "value": "STARTED" } } }, "system_hardware": { "gpio-buttons": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "ir_controller": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } }, "rotaryencoder2": { "enabled": { "type": "boolean", "value": true }, "status": { "type": "string", "value": "STARTED" } } } } # cat /etc/mpd.conf --------------- # Volumio MPD Configuration File # Files and directories ####################################################### music_directory "/var/lib/mpd/music" playlist_directory "/var/lib/mpd/playlists" db_file "/var/lib/mpd/tag_cache" log_file "/var/log/mpd.log" #pid_file "/var/run/mpd/pid" #state_file "/var/lib/mpd/state" #sticker_file "/var/lib/mpd/sticker.sql" ############################################################################### # General music daemon options ################################################ user "mpd" group "audio" bind_to_address "any" #port "6600" log_level "default" #save_absolute_paths_in_playlists "no" #metadata_to_use "artist,album,title,track,name,genre,date,composer,performer,disc" auto_update "no" #auto_update_depth "3" ############################################################################### # Symbolic link behavior ###################################################### follow_outside_symlinks "yes" follow_inside_symlinks "yes" ############################################################################### # Input ####################################################################### # input { plugin "curl" # proxy "proxy.isp.com:8080" # proxy_user "user" # proxy_password "password" } ############################################################################### # Decoder ################################################################ decoder { plugin "faad" enabled "no" } ############################################################################### # Audio Output ################################################################ resampler { plugin "soxr" quality "high" threads "1" } audio_output { type "alsa" name "alsa" device "volumio" dop "no" } audio_output { type "fifo" enabled "no" name "multiroom" path "/tmp/snapfifo" format "44100:16:2" } #replaygain "album" #replaygain_preamp "0" volume_normalization "no" ############################################################################### # MPD Internal Buffering ###################################################### audio_buffer_size "2048" ############################################################################### # Resource Limitations ######################################################## #connection_timeout "60" max_connections "20" max_playlist_length "81920" max_command_list_size "81920" max_output_buffer_size "81920" ############################################################################### # Character Encoding ########################################################## filesystem_charset "UTF-8" ############################################################################### # volumio endpointstest --------------- TESTING REMOTE ENDPOINTS https://google.com, 658 ms: OK https://www.googleapis.com, 588 ms: OK https://securetoken.googleapis.com, 611 ms: OK https://myvolumio.firebaseio.com, 620 ms: OK https://functions.volumio.cloud, 635 ms: OK https://oauth-performer.dfs.volumio.org, 388 ms: OK https://browsing-performer.dfs.volumio.org, 607 ms: OK http://cddb.volumio.org, 703 ms: OK https://functions.volumio.cloud, 577 ms: OK http://pushupdates.volumio.org, 435 ms: OK http://plugins.volumio.org, 820 ms: OK https://database.volumio.cloud, 719 ms: OK https://radio-directory.firebaseapp.com, 558 ms: OK ---------- REMOTE ENDPOINTS TEST OK, all Endpoints are reachable ---------- # cat /data/updatesHistoryFile --------------- --- Fri Oct 20 2023 13:45:51 GMT+0000 (Coordinated Universal Time) {"systemversion":"3.569","builddate":"Fri 20 Oct 2023 03:38:28 PM CEST","variant":"volumio","hardware":"pi"} --- # sudo journalctl -p 7 --------------- -- Logs begin at Fri 2023-11-10 17:01:45 CET, end at Sat 2023-11-11 11:26:40 CET. -- Nov 10 17:01:45 volumio kernel: Booting Linux on physical CPU 0x0 Nov 10 17:01:45 volumio kernel: Linux version 6.1.58-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1690 SMP Tue Oct 17 15:35:01 BST 2023 Nov 10 17:01:45 volumio kernel: CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d Nov 10 17:01:45 volumio kernel: CPU: div instructions available: patching division code Nov 10 17:01:45 volumio kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Nov 10 17:01:45 volumio kernel: OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2 Nov 10 17:01:45 volumio kernel: random: crng init done Nov 10 17:01:45 volumio kernel: Memory policy: Data cache writealloc Nov 10 17:01:45 volumio kernel: Reserved memory: created CMA memory pool at 0x3a000000, size 64 MiB Nov 10 17:01:45 volumio kernel: OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool Nov 10 17:01:45 volumio kernel: Zone ranges: Nov 10 17:01:45 volumio kernel: DMA [mem 0x0000000000000000-0x000000003dffffff] Nov 10 17:01:45 volumio kernel: Normal empty Nov 10 17:01:45 volumio kernel: Movable zone start for each node Nov 10 17:01:45 volumio kernel: Early memory node ranges Nov 10 17:01:45 volumio kernel: node 0: [mem 0x0000000000000000-0x000000003dffffff] Nov 10 17:01:45 volumio kernel: Initmem setup node 0 [mem 0x0000000000000000-0x000000003dffffff] Nov 10 17:01:45 volumio kernel: percpu: Embedded 17 pages/cpu s37012 r8192 d24428 u69632 Nov 10 17:01:45 volumio kernel: pcpu-alloc: s37012 r8192 d24428 u69632 alloc=17*4096 Nov 10 17:01:45 volumio kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Nov 10 17:01:45 volumio kernel: Built 1 zonelists, mobility grouping on. Total pages: 251720 Nov 10 17:01:45 volumio kernel: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1280 bcm2708_fb.fbheight=400 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 Nov 10 17:01:45 volumio kernel: Kernel parameter elevator= does not have any effect anymore. Please use sysfs to set IO scheduler for individual devices. Nov 10 17:01:45 volumio kernel: Unknown kernel command line parameters "splash imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh bootdelay=5", will be passed to user space. Nov 10 17:01:45 volumio kernel: Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) Nov 10 17:01:45 volumio kernel: Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) Nov 10 17:01:45 volumio kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Nov 10 17:01:45 volumio kernel: Memory: 908956K/1015808K available (10240K kernel code, 1454K rwdata, 3224K rodata, 1024K init, 611K bss, 41316K reserved, 65536K cma-reserved) Nov 10 17:01:45 volumio kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Nov 10 17:01:45 volumio kernel: ftrace: allocating 34927 entries in 103 pages Nov 10 17:01:45 volumio kernel: ftrace: allocated 103 pages with 5 groups Nov 10 17:01:45 volumio kernel: trace event string verifier disabled Nov 10 17:01:45 volumio kernel: rcu: Hierarchical RCU implementation. Nov 10 17:01:45 volumio kernel: Rude variant of Tasks RCU enabled. Nov 10 17:01:45 volumio kernel: Tracing variant of Tasks RCU enabled. Nov 10 17:01:45 volumio kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Nov 10 17:01:45 volumio kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Nov 10 17:01:45 volumio kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Nov 10 17:01:45 volumio kernel: arch_timer: cp15 timer(s) running at 19.20MHz (phys). Nov 10 17:01:45 volumio kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns Nov 10 17:01:45 volumio kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns Nov 10 17:01:45 volumio kernel: Switching to timer-based delay loop, resolution 52ns Nov 10 17:01:45 volumio kernel: Console: colour dummy device 80x30 Nov 10 17:01:45 volumio kernel: printk: console [tty1] enabled Nov 10 17:01:45 volumio kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) Nov 10 17:01:45 volumio kernel: CPU: Testing write buffer coherency: ok Nov 10 17:01:45 volumio kernel: pid_max: default: 32768 minimum: 301 Nov 10 17:01:45 volumio kernel: LSM: Security Framework initializing Nov 10 17:01:45 volumio kernel: Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Nov 10 17:01:45 volumio kernel: Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) Nov 10 17:01:45 volumio kernel: cgroup: Disabling memory control group subsystem Nov 10 17:01:45 volumio kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Nov 10 17:01:45 volumio kernel: cblist_init_generic: Setting adjustable number of callback queues. Nov 10 17:01:45 volumio kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Nov 10 17:01:45 volumio kernel: cblist_init_generic: Setting adjustable number of callback queues. Nov 10 17:01:45 volumio kernel: cblist_init_generic: Setting shift to 2 and lim to 1. Nov 10 17:01:45 volumio kernel: Setting up static identity map for 0x100000 - 0x10003c Nov 10 17:01:45 volumio kernel: rcu: Hierarchical SRCU implementation. Nov 10 17:01:45 volumio kernel: rcu: Max phase no-delay instances is 1000. Nov 10 17:01:45 volumio kernel: smp: Bringing up secondary CPUs ... Nov 10 17:01:45 volumio kernel: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 Nov 10 17:01:45 volumio kernel: CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 Nov 10 17:01:45 volumio kernel: CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 Nov 10 17:01:45 volumio kernel: smp: Brought up 1 node, 4 CPUs Nov 10 17:01:45 volumio kernel: SMP: Total of 4 processors activated (153.60 BogoMIPS). Nov 10 17:01:45 volumio kernel: CPU: All CPU(s) started in HYP mode. Nov 10 17:01:45 volumio kernel: CPU: Virtualization extensions available. Nov 10 17:01:45 volumio kernel: devtmpfs: initialized Nov 10 17:01:45 volumio kernel: VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 Nov 10 17:01:45 volumio kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Nov 10 17:01:45 volumio kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Nov 10 17:01:45 volumio kernel: pinctrl core: initialized pinctrl subsystem Nov 10 17:01:45 volumio kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Nov 10 17:01:45 volumio kernel: DMA: preallocated 1024 KiB pool for atomic coherent allocations Nov 10 17:01:45 volumio kernel: audit: initializing netlink subsys (disabled) Nov 10 17:01:45 volumio kernel: audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 Nov 10 17:01:45 volumio kernel: thermal_sys: Registered thermal governor 'step_wise' Nov 10 17:01:45 volumio kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Nov 10 17:01:45 volumio kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Nov 10 17:01:45 volumio kernel: Serial: AMBA PL011 UART driver Nov 10 17:01:45 volumio kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled Nov 10 17:01:45 volumio kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:42:39, variant start Nov 10 17:01:45 volumio kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Nov 10 17:01:45 volumio kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Nov 10 17:01:45 volumio kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 Nov 10 17:01:45 volumio kernel: SCSI subsystem initialized Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver usbfs Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver hub Nov 10 17:01:45 volumio kernel: usbcore: registered new device driver usb Nov 10 17:01:45 volumio kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Nov 10 17:01:45 volumio kernel: pps_core: LinuxPPS API ver. 1 registered Nov 10 17:01:45 volumio kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Nov 10 17:01:45 volumio kernel: PTP clock support registered Nov 10 17:01:45 volumio kernel: clocksource: Switched to clocksource arch_sys_counter Nov 10 17:01:45 volumio kernel: VFS: Disk quotas dquot_6.6.0 Nov 10 17:01:45 volumio kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Nov 10 17:01:45 volumio kernel: FS-Cache: Loaded Nov 10 17:01:45 volumio kernel: CacheFiles: Loaded Nov 10 17:01:45 volumio kernel: NET: Registered PF_INET protocol family Nov 10 17:01:45 volumio kernel: IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) Nov 10 17:01:45 volumio kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Nov 10 17:01:45 volumio kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Nov 10 17:01:45 volumio kernel: TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) Nov 10 17:01:45 volumio kernel: TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) Nov 10 17:01:45 volumio kernel: TCP: Hash tables configured (established 8192 bind 8192) Nov 10 17:01:45 volumio kernel: UDP hash table entries: 512 (order: 2, 16384 bytes, linear) Nov 10 17:01:45 volumio kernel: UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) Nov 10 17:01:45 volumio kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Nov 10 17:01:45 volumio kernel: RPC: Registered named UNIX socket transport module. Nov 10 17:01:45 volumio kernel: RPC: Registered udp transport module. Nov 10 17:01:45 volumio kernel: RPC: Registered tcp transport module. Nov 10 17:01:45 volumio kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Nov 10 17:01:45 volumio kernel: Trying to unpack rootfs image as initramfs... Nov 10 17:01:45 volumio kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Nov 10 17:01:45 volumio kernel: Initialise system trusted keyrings Nov 10 17:01:45 volumio kernel: workingset: timestamp_bits=14 max_order=18 bucket_order=4 Nov 10 17:01:45 volumio kernel: zbud: loaded Nov 10 17:01:45 volumio kernel: NFS: Registering the id_resolver key type Nov 10 17:01:45 volumio kernel: Key type id_resolver registered Nov 10 17:01:45 volumio kernel: Key type id_legacy registered Nov 10 17:01:45 volumio kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Nov 10 17:01:45 volumio kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Nov 10 17:01:45 volumio kernel: Key type asymmetric registered Nov 10 17:01:45 volumio kernel: Asymmetric key parser 'x509' registered Nov 10 17:01:45 volumio kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Nov 10 17:01:45 volumio kernel: io scheduler mq-deadline registered Nov 10 17:01:45 volumio kernel: io scheduler kyber registered Nov 10 17:01:45 volumio kernel: bcm2708_fb soc:fb: FB found 1 display(s) Nov 10 17:01:45 volumio kernel: Console: switching to colour frame buffer device 160x25 Nov 10 17:01:45 volumio kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 1280x400 Nov 10 17:01:45 volumio kernel: bcm2835-rng 3f104000.rng: hwrng registered Nov 10 17:01:45 volumio kernel: vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) Nov 10 17:01:45 volumio kernel: brd: module loaded Nov 10 17:01:45 volumio kernel: loop: module loaded Nov 10 17:01:45 volumio kernel: Loading iSCSI transport class v2.0-870. Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver lan78xx Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver smsc95xx Nov 10 17:01:45 volumio kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Nov 10 17:01:45 volumio kernel: Core Release: 2.80a Nov 10 17:01:45 volumio kernel: Setting default values for core params Nov 10 17:01:45 volumio kernel: Finished setting default values for core params Nov 10 17:01:45 volumio kernel: Freeing initrd memory: 13620K Nov 10 17:01:45 volumio kernel: Using Buffer DMA mode Nov 10 17:01:45 volumio kernel: Periodic Transfer Interrupt Enhancement - disabled Nov 10 17:01:45 volumio kernel: Multiprocessor Interrupt Enhancement - disabled Nov 10 17:01:45 volumio kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Nov 10 17:01:45 volumio kernel: Dedicated Tx FIFOs mode Nov 10 17:01:45 volumio kernel: Nov 10 17:01:45 volumio kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = ba104000 dma = 0xfa104000 len=9024 Nov 10 17:01:45 volumio kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Nov 10 17:01:45 volumio kernel: dwc_otg: Microframe scheduler enabled Nov 10 17:01:45 volumio kernel: Nov 10 17:01:45 volumio kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Nov 10 17:01:45 volumio kernel: Nov 10 17:01:45 volumio kernel: WARN::hcd_init_fiq:458: FIQ ASM at 807cc618 length 36 Nov 10 17:01:45 volumio kernel: Nov 10 17:01:45 volumio kernel: WARN::hcd_init_fiq:497: MPHI regs_base at be810000 Nov 10 17:01:45 volumio kernel: dwc_otg 3f980000.usb: DWC OTG Controller Nov 10 17:01:45 volumio kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Nov 10 17:01:45 volumio kernel: dwc_otg 3f980000.usb: irq 89, io mem 0x00000000 Nov 10 17:01:45 volumio kernel: Init: Port Power? op_state=1 Nov 10 17:01:45 volumio kernel: Init: Power Port (0) Nov 10 17:01:45 volumio kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Nov 10 17:01:45 volumio kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Nov 10 17:01:45 volumio kernel: usb usb1: Product: DWC OTG Controller Nov 10 17:01:45 volumio kernel: usb usb1: Manufacturer: Linux 6.1.58-v7+ dwc_otg_hcd Nov 10 17:01:45 volumio kernel: usb usb1: SerialNumber: 3f980000.usb Nov 10 17:01:45 volumio kernel: hub 1-0:1.0: USB hub found Nov 10 17:01:45 volumio kernel: hub 1-0:1.0: 1 port detected Nov 10 17:01:45 volumio kernel: dwc_otg: FIQ enabled Nov 10 17:01:45 volumio kernel: dwc_otg: NAK holdoff enabled Nov 10 17:01:45 volumio kernel: dwc_otg: FIQ split-transaction FSM enabled Nov 10 17:01:45 volumio kernel: Module dwc_common_port init Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver usb-storage Nov 10 17:01:45 volumio kernel: mousedev: PS/2 mouse device common for all mice Nov 10 17:01:45 volumio kernel: sdhci: Secure Digital Host Controller Interface driver Nov 10 17:01:45 volumio kernel: sdhci: Copyright(c) Pierre Ossman Nov 10 17:01:45 volumio kernel: sdhci-pltfm: SDHCI platform and OF driver helper Nov 10 17:01:45 volumio kernel: ledtrig-cpu: registered to indicate activity on CPUs Nov 10 17:01:45 volumio kernel: hid: raw HID events driver (C) Jiri Kosina Nov 10 17:01:45 volumio kernel: usbcore: registered new interface driver usbhid Nov 10 17:01:45 volumio kernel: usbhid: USB HID core driver Nov 10 17:01:45 volumio kernel: Initializing XFRM netlink socket Nov 10 17:01:45 volumio kernel: NET: Registered PF_PACKET protocol family Nov 10 17:01:45 volumio kernel: Key type dns_resolver registered Nov 10 17:01:45 volumio kernel: Registering SWP/SWPB emulation handler Nov 10 17:01:45 volumio kernel: registered taskstats version 1 Nov 10 17:01:45 volumio kernel: Loading compiled-in X.509 certificates Nov 10 17:01:45 volumio kernel: Key type .fscrypt registered Nov 10 17:01:45 volumio kernel: Key type fscrypt-provisioning registered Nov 10 17:01:45 volumio kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Nov 10 17:01:45 volumio kernel: 3f201000.serial: ttyAMA1 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 Nov 10 17:01:45 volumio kernel: serial serial0: tty port ttyAMA1 registered Nov 10 17:01:45 volumio kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Nov 10 17:01:45 volumio kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Nov 10 17:01:45 volumio kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Nov 10 17:01:45 volumio kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Nov 10 17:01:45 volumio kernel: sdhost: log_buf @ db7ad65b (fa107000) Nov 10 17:01:45 volumio kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Nov 10 17:01:45 volumio kernel: of_cfs_init Nov 10 17:01:45 volumio kernel: of_cfs_init: OK Nov 10 17:01:45 volumio kernel: Freeing unused kernel image (initmem) memory: 1024K Nov 10 17:01:45 volumio kernel: Indeed it is in host mode hprt0 = 00021501 Nov 10 17:01:45 volumio kernel: mmc0: host does not support reading read-only switch, assuming write-enable Nov 10 17:01:45 volumio kernel: mmc0: new high speed SDHC card at address aaaa Nov 10 17:01:45 volumio kernel: mmcblk0: mmc0:aaaa SE32G 29.7 GiB Nov 10 17:01:45 volumio kernel: mmcblk0: p1 p2 p3 Nov 10 17:01:45 volumio kernel: mmcblk0: mmc0:aaaa SE32G 29.7 GiB (quirks 0x00004000) Nov 10 17:01:45 volumio kernel: mmc1: new high speed SDIO card at address 0001 Nov 10 17:01:45 volumio kernel: Run /init as init process Nov 10 17:01:45 volumio kernel: with arguments: Nov 10 17:01:45 volumio kernel: /init Nov 10 17:01:45 volumio kernel: splash Nov 10 17:01:45 volumio kernel: with environment: Nov 10 17:01:45 volumio kernel: HOME=/ Nov 10 17:01:45 volumio kernel: TERM=linux Nov 10 17:01:45 volumio kernel: imgpart=/dev/mmcblk0p2 Nov 10 17:01:45 volumio kernel: imgfile=/volumio_current.sqsh Nov 10 17:01:45 volumio kernel: bootdelay=5 Nov 10 17:01:45 volumio kernel: usb 1-1: new high-speed USB device number 2 using dwc_otg Nov 10 17:01:45 volumio kernel: Indeed it is in host mode hprt0 = 00001101 Nov 10 17:01:45 volumio initramfs: Booting Volumio for BCM2835 Nov 10 17:01:45 volumio initramfs: This script mounts rootfs RO with an overlay RW layer. Nov 10 17:01:45 volumio kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Nov 10 17:01:45 volumio initramfs: IMGPART=/dev/mmcblk0p2 Nov 10 17:01:45 volumio initramfs: IMGFILE=/volumio_current.sqsh Nov 10 17:01:45 volumio initramfs: Boot delay (except first time) will be 5 seconds Nov 10 17:01:45 volumio initramfs: /dev/mmcblk0p2: Nov 10 17:01:45 volumio kernel: usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 Nov 10 17:01:45 volumio kernel: usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Nov 10 17:01:45 volumio kernel: hub 1-1:1.0: USB hub found Nov 10 17:01:45 volumio kernel: hub 1-1:1.0: 5 ports detected Nov 10 17:01:45 volumio kernel: EXT4-fs (mmcblk0p2): recovery complete Nov 10 17:01:45 volumio kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Nov 10 17:01:45 volumio initramfs: Doing a 5 second delay here to give kernel load a headstart Nov 10 17:01:45 volumio kernel: usb 1-1.1: new high-speed USB device number 3 using dwc_otg Nov 10 17:01:45 volumio kernel: usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 Nov 10 17:01:45 volumio kernel: usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Nov 10 17:01:45 volumio kernel: smsc95xx v2.0.0 Nov 10 17:01:45 volumio kernel: SMSC LAN8700 usb-001:003:01: attached PHY driver (mii_bus:phy_addr=usb-001:003:01, irq=199) Nov 10 17:01:45 volumio kernel: smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:ef:86:2f Nov 10 17:01:45 volumio kernel: usb 1-1.3: new full-speed USB device number 4 using dwc_otg Nov 10 17:01:45 volumio kernel: usb 1-1.3: New USB device found, idVendor=0712, idProduct=0009, bcdDevice= 2.00 Nov 10 17:01:45 volumio kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Nov 10 17:01:45 volumio kernel: usb 1-1.3: Product: WaveShare Nov 10 17:01:45 volumio kernel: usb 1-1.3: Manufacturer: WaveShare Nov 10 17:01:45 volumio kernel: usb 1-1.3: SerialNumber: 000000000089 Nov 10 17:01:45 volumio kernel: input: WaveShare WaveShare as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:0712:0009.0001/input/input0 Nov 10 17:01:45 volumio kernel: hid-generic 0003:0712:0009.0001: input,hidraw0: USB HID v1.11 Device [WaveShare WaveShare] on usb-3f980000.usb-1.3/input0 Nov 10 17:01:45 volumio initramfs: Checking for USB updates Nov 10 17:01:45 volumio initramfs: No USB device detected (when incorrect, try adding 'bootdelay=5' to your boot cmdline) Nov 10 17:01:45 volumio kernel: loop0: detected capacity change from 0 to 962048 Nov 10 17:01:45 volumio kernel: EXT4-fs (mmcblk0p3): recovery complete Nov 10 17:01:45 volumio kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Nov 10 17:01:45 volumio initramfs: With Option: Nov 10 17:01:45 volumio initramfs: VOLUMIO_VERSION="3.569" Nov 10 17:01:45 volumio initramfs: Finish initramfs, continue booting Volumio Nov 10 17:01:45 volumio systemd[1]: System time before build time, advancing clock. Nov 10 17:01:45 volumio kernel: NET: Registered PF_INET6 protocol family Nov 10 17:01:45 volumio kernel: Segment Routing with IPv6 Nov 10 17:01:45 volumio kernel: In-situ OAM (IOAM) with IPv6 Nov 10 17:01:45 volumio systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Nov 10 17:01:45 volumio systemd[1]: Detected architecture arm. Nov 10 17:01:45 volumio systemd[1]: Set hostname to . Nov 10 17:01:45 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 10 17:01:45 volumio systemd[1]: Listening on Journal Socket. Nov 10 17:01:45 volumio systemd[1]: Reached target System Time Synchronized. Nov 10 17:01:45 volumio systemd[1]: Listening on Journal Socket (/dev/log). Nov 10 17:01:45 volumio systemd[1]: Mounting RPC Pipe File System... Nov 10 17:01:45 volumio systemd[1]: Starting Restore / save the current clock... Nov 10 17:01:45 volumio systemd[1]: Starting Remount Root and Kernel File Systems... Nov 10 17:01:45 volumio kernel: i2c_dev: i2c /dev entries driver Nov 10 17:01:45 volumio systemd-journald[206]: Journal started Nov 10 17:01:45 volumio systemd-journald[206]: Runtime journal (/run/log/journal/4ceeebcde4a5f04b591e77826532825c) is 3.7M, max 30.0M, 26.2M free. Nov 10 17:01:45 volumio systemd-modules-load[196]: Inserted module 'i2c_dev' Nov 10 17:01:45 volumio fake-hwclock[189]: Fri Nov 10 16:01:45 UTC 2023 Nov 10 17:01:45 volumio systemd[1]: Started Apply Kernel Variables. Nov 10 17:01:45 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 10 17:01:45 volumio systemd[1]: Started Create Static Device Nodes in /dev. Nov 10 17:01:45 volumio systemd[1]: Reached target Local File Systems (Pre). Nov 10 17:01:45 volumio systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Nov 10 17:01:45 volumio systemd[1]: Mounting /var/log... Nov 10 17:01:45 volumio systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Nov 10 17:01:45 volumio systemd[1]: Mounting /tmp... Nov 10 17:01:45 volumio systemd[1]: Mounting /var/spool/cups... Nov 10 17:01:45 volumio systemd[1]: Starting udev Kernel Device Manager... Nov 10 17:01:45 volumio systemd[1]: Mounted /var/log. Nov 10 17:01:45 volumio systemd[1]: Mounted /tmp. Nov 10 17:01:45 volumio systemd[1]: Mounted /var/spool/cups. Nov 10 17:01:45 volumio systemd[1]: Mounting /var/spool/cups/tmp... Nov 10 17:01:45 volumio systemd[1]: Starting Flush Journal to Persistent Storage... Nov 10 17:01:45 volumio systemd[1]: Mounted /var/spool/cups/tmp. Nov 10 17:01:45 volumio systemd[1]: Started udev Coldplug all Devices. Nov 10 17:01:45 volumio systemd[1]: Starting Helper to synchronize boot up for ifupdown... Nov 10 17:01:45 volumio systemd-udevd[229]: Network interface NamePolicy= disabled on kernel command line, ignoring. Nov 10 17:01:45 volumio systemd[1]: Started Helper to synchronize boot up for ifupdown. Nov 10 17:01:45 volumio systemd-journald[206]: Runtime journal (/run/log/journal/4ceeebcde4a5f04b591e77826532825c) is 3.7M, max 30.0M, 26.2M free. Nov 10 17:01:45 volumio systemd[1]: Started Flush Journal to Persistent Storage. Nov 10 17:01:45 volumio systemd[1]: Started udev Kernel Device Manager. Nov 10 17:01:45 volumio systemd[1]: Starting Show Plymouth Boot Screen... Nov 10 17:01:45 volumio systemd[1]: Received SIGRTMIN+20 from PID 246 (plymouthd). Nov 10 17:01:45 volumio systemd[1]: Started Show Plymouth Boot Screen. Nov 10 17:01:45 volumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 10 17:01:45 volumio systemd[1]: Reached target Paths. Nov 10 17:01:45 volumio systemd[1]: Reached target Local Encrypted Volumes. Nov 10 17:01:45 volumio systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Nov 10 17:01:46 volumio kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Nov 10 17:01:46 volumio kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Nov 10 17:01:46 volumio kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Nov 10 17:01:46 volumio kernel: [vc_sm_connected_init]: start Nov 10 17:01:46 volumio kernel: mc: Linux media interface: v0.10 Nov 10 17:01:46 volumio kernel: [vc_sm_connected_init]: installed successfully Nov 10 17:01:46 volumio kernel: videodev: Linux video capture interface: v2.00 Nov 10 17:01:46 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 10 17:01:46 volumio kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Nov 10 17:01:46 volumio kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Nov 10 17:01:46 volumio systemd[1]: Found device /dev/mmcblk0p1. Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Nov 10 17:01:46 volumio kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Nov 10 17:01:46 volumio kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Nov 10 17:01:46 volumio kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Nov 10 17:01:46 volumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 10 17:01:46 volumio kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Nov 10 17:01:47 volumio systemd-udevd[235]: Using default interface naming scheme 'v240'. Nov 10 17:01:47 volumio kernel: Bluetooth: Core ver 2.22 Nov 10 17:01:47 volumio kernel: NET: Registered PF_BLUETOOTH protocol family Nov 10 17:01:47 volumio kernel: Bluetooth: HCI device and connection manager initialized Nov 10 17:01:47 volumio kernel: Bluetooth: HCI socket layer initialized Nov 10 17:01:47 volumio kernel: Bluetooth: L2CAP socket layer initialized Nov 10 17:01:47 volumio kernel: Bluetooth: SCO socket layer initialized Nov 10 17:01:47 volumio systemd[1]: Starting File System Check on /dev/mmcblk0p1... Nov 10 17:01:47 volumio kernel: Bluetooth: HCI UART driver ver 2.3 Nov 10 17:01:47 volumio kernel: Bluetooth: HCI UART protocol H4 registered Nov 10 17:01:47 volumio kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Nov 10 17:01:47 volumio kernel: Bluetooth: HCI UART protocol Broadcom registered Nov 10 17:01:47 volumio kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Nov 10 17:01:47 volumio kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Nov 10 17:01:47 volumio systemd-udevd[235]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 10 17:01:47 volumio systemd[1]: Started File System Check Daemon to report status. Nov 10 17:01:47 volumio kernel: uart-pl011 3f201000.serial: no DMA platform data Nov 10 17:01:47 volumio kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Nov 10 17:01:47 volumio kernel: input: WaveShare WaveShare as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:0712:0009.0001/input/input1 Nov 10 17:01:47 volumio kernel: hid-multitouch 0003:0712:0009.0001: input,hidraw0: USB HID v1.11 Device [WaveShare WaveShare] on usb-3f980000.usb-1.3/input0 Nov 10 17:01:47 volumio kernel: Bluetooth: hci0: BCM: chip id 94 Nov 10 17:01:47 volumio kernel: Bluetooth: hci0: BCM: features 0x2e Nov 10 17:01:47 volumio kernel: Bluetooth: hci0: BCM43430A1 Nov 10 17:01:47 volumio kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0000 Nov 10 17:01:47 volumio kernel: Bluetooth: hci0: BCM43430A1 'brcm/BCM43430A1.hcd' Patch Nov 10 17:01:47 volumio systemd-udevd[239]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 10 17:01:47 volumio systemd-fsck[328]: fsck.fat 4.1 (2017-01-24) Nov 10 17:01:47 volumio systemd-fsck[328]: /dev/mmcblk0p1: 432 files, 33744/46774 clusters Nov 10 17:01:47 volumio kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Nov 10 17:01:47 volumio kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Nov 10 17:01:47 volumio kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Nov 10 17:01:47 volumio systemd[1]: Started File System Check on /dev/mmcblk0p1. Nov 10 17:01:48 volumio kernel: brcmfmac: F1 signature read @0x18000000=0x1541a9a6 Nov 10 17:01:48 volumio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1 Nov 10 17:01:48 volumio kernel: usbcore: registered new interface driver brcmfmac Nov 10 17:01:48 volumio kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Jul 19 2021 03:24:18 version 7.45.98 (TOB) (56df937 CY) FWID 01-8e14b897 Nov 10 17:01:48 volumio systemd-udevd[242]: Using default interface naming scheme 'v240'. Nov 10 17:01:48 volumio systemd-udevd[242]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 10 17:01:48 volumio kernel: Bluetooth: hci0: BCM: features 0x2e Nov 10 17:01:48 volumio kernel: Bluetooth: hci0: BCM43438A1 37.4MHz Raspberry Pi 3-0141 Nov 10 17:01:48 volumio kernel: Bluetooth: hci0: BCM43430A1 (001.002.009) build 0508 Nov 10 17:01:48 volumio systemd-udevd[244]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 10 17:01:49 volumio systemd-udevd[243]: Process '/sbin/crda' failed with exit code 255. Nov 10 17:01:49 volumio systemd-udevd[237]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in SMSC9512/9514 Fast Ethernet Adapter being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in /sys/subsystem/net/devices/wlan0 being skipped. Nov 10 17:01:49 volumio systemd[1]: Created slice system-bthelper.slice. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in Huge Pages File System being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in FUSE Control File System being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Nov 10 17:01:49 volumio systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Nov 10 17:01:49 volumio systemd[1]: Mounting /boot... Nov 10 17:01:49 volumio systemd[1]: Starting Load/Save RF Kill Switch Status... Nov 10 17:01:49 volumio systemd[1]: Mounted /boot. Nov 10 17:01:49 volumio systemd[1]: Reached target Local File Systems. Nov 10 17:01:49 volumio systemd[1]: Starting Raise network interfaces... Nov 10 17:01:49 volumio systemd[1]: Started ifup for eth0. Nov 10 17:01:49 volumio systemd[1]: Starting Create Volatile Files and Directories... Nov 10 17:01:49 volumio systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Nov 10 17:01:49 volumio systemd[1]: Started ifup for wlan0. Nov 10 17:01:49 volumio systemd[1]: Starting Preprocess NFS configuration... Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Nov 10 17:01:49 volumio systemd[1]: plymouth-read-write.service: Succeeded. Nov 10 17:01:49 volumio systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Nov 10 17:01:49 volumio systemd[1]: Started Load/Save RF Kill Switch Status. Nov 10 17:01:49 volumio systemd[1]: Received SIGRTMIN+20 from PID 246 (plymouthd). Nov 10 17:01:49 volumio systemd[1]: nfs-config.service: Succeeded. Nov 10 17:01:49 volumio systemd[1]: Started Preprocess NFS configuration. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Nov 10 17:01:49 volumio systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Nov 10 17:01:49 volumio systemd[1]: Reached target NFS client services. Nov 10 17:01:49 volumio systemd[1]: Started Create Volatile Files and Directories. Nov 10 17:01:50 volumio systemd[1]: Starting Update UTMP about System Boot/Shutdown... Nov 10 17:01:50 volumio systemd[1]: Starting RPC bind portmap service... Nov 10 17:01:50 volumio systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Nov 10 17:01:50 volumio systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Nov 10 17:01:50 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 10 17:01:50 volumio systemd[1]: Started Update UTMP about System Boot/Shutdown. Nov 10 17:01:50 volumio systemd[1]: Reached target System Initialization. Nov 10 17:01:50 volumio systemd[1]: Started Daily Cleanup of Temporary Directories. Nov 10 17:01:50 volumio systemd[1]: Started Daily apt download activities. Nov 10 17:01:50 volumio systemd[1]: Started Daily apt upgrade and clean activities. Nov 10 17:01:50 volumio kernel: 8021q: 802.1Q VLAN Support v1.8 Nov 10 17:01:50 volumio systemd[1]: Listening on mpd.socket. Nov 10 17:01:50 volumio systemd[1]: Listening on lircd.socket. Nov 10 17:01:50 volumio systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Nov 10 17:01:50 volumio systemd[1]: Listening on triggerhappy.socket. Nov 10 17:01:50 volumio systemd[1]: Started Daily man-db regeneration. Nov 10 17:01:50 volumio systemd[1]: Reached target Timers. Nov 10 17:01:50 volumio systemd[1]: Listening on D-Bus System Message Bus Socket. Nov 10 17:01:50 volumio systemd[1]: Reached target Sockets. Nov 10 17:01:50 volumio systemd[1]: Reached target Basic System. Nov 10 17:01:50 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Nov 10 17:01:50 volumio systemd[1]: Started Volumio Iptables Module. Nov 10 17:01:50 volumio systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Nov 10 17:01:50 volumio systemd[1]: Starting dhcpcd on all interfaces... Nov 10 17:01:50 volumio systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Nov 10 17:01:50 volumio systemd[1]: Starting Wireless Services... Nov 10 17:01:50 volumio systemd[1]: Started Manage Sound Card State (restore and store). Nov 10 17:01:50 volumio systemd[1]: Starting triggerhappy global hotkey daemon... Nov 10 17:01:50 volumio alsactl[523]: alsactl 1.1.8 daemon started Nov 10 17:01:50 volumio systemd[1]: Starting Configure Bluetooth Modems connected by UART... Nov 10 17:01:50 volumio systemd[1]: Starting Save/Restore Sound Card State... Nov 10 17:01:50 volumio systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Nov 10 17:01:50 volumio systemd[1]: Starting Login Service... Nov 10 17:01:50 volumio systemd[1]: Started D-Bus System Message Bus. Nov 10 17:01:50 volumio dhcpcd[521]: Not running dhcpcd because /etc/network/interfaces Nov 10 17:01:50 volumio dhcpcd[521]: defines some interfaces that will use a Nov 10 17:01:50 volumio dhcpcd[521]: DHCP client or static address Nov 10 17:01:50 volumio thd[524]: Unable to parse trigger line: Nov 10 17:01:50 volumio thd[524]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Nov 10 17:01:50 volumio thd[524]: Unable to parse trigger line: Nov 10 17:01:50 volumio thd[524]: Unable to parse trigger line: Nov 10 17:01:50 volumio thd[524]: Found socket passed from systemd Nov 10 17:01:50 volumio systemd[1]: Starting WPA supplicant... Nov 10 17:01:50 volumio systemd[1]: Started volumio-remote-updater.service. Nov 10 17:01:50 volumio systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Nov 10 17:01:50 volumio systemd[1]: Started RPC bind portmap service. Nov 10 17:01:50 volumio systemd[1]: Started triggerhappy global hotkey daemon. Nov 10 17:01:50 volumio systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Nov 10 17:01:50 volumio systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Nov 10 17:01:50 volumio systemd[1]: Failed to start dhcpcd on all interfaces. Nov 10 17:01:50 volumio systemd[1]: Started Save/Restore Sound Card State. Nov 10 17:01:50 volumio systemd-logind[529]: New seat seat0. Nov 10 17:01:50 volumio systemd[1]: Reached target Sound Card. Nov 10 17:01:50 volumio systemd[1]: Reached target RPC Port Mapper. Nov 10 17:01:50 volumio systemd[1]: Reached target Remote File Systems (Pre). Nov 10 17:01:50 volumio systemd[1]: Reached target Remote File Systems. Nov 10 17:01:50 volumio sh[422]: eth0: waiting for carrier Nov 10 17:01:50 volumio kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup Nov 10 17:01:50 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Nov 10 17:01:50 volumio dhcpcd[471]: eth0: waiting for carrier Nov 10 17:01:50 volumio sh[427]: wlan0=wlan0 Nov 10 17:01:51 volumio sh[422]: eth0: carrier acquired Nov 10 17:01:50 volumio systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Nov 10 17:01:50 volumio dhcpcd[471]: eth0: carrier acquired Nov 10 17:01:51 volumio sh[422]: DUID 00:01:00:01:2c:c5:40:e5:b8:27:eb:ef:86:2f Nov 10 17:01:51 volumio sh[422]: eth0: IAID eb:ef:86:2f Nov 10 17:01:51 volumio sh[422]: eth0: adding address fe80::fca1:9891:6b0d:7c7b Nov 10 17:01:51 volumio sh[422]: ipv6_addaddr1: Permission denied Nov 10 17:01:51 volumio dhcpcd[471]: DUID 00:01:00:01:2c:c5:40:e5:b8:27:eb:ef:86:2f Nov 10 17:01:51 volumio dhcpcd[471]: eth0: IAID eb:ef:86:2f Nov 10 17:01:51 volumio dhcpcd[471]: eth0: adding address fe80::fca1:9891:6b0d:7c7b Nov 10 17:01:51 volumio dhcpcd[471]: ipv6_addaddr1: Permission denied Nov 10 17:01:51 volumio avahi-daemon[542]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Nov 10 17:01:51 volumio avahi-daemon[542]: Successfully dropped root privileges. Nov 10 17:01:51 volumio avahi-daemon[542]: avahi-daemon 0.7 starting up. Nov 10 17:01:51 volumio systemd[1]: Started Login Service. Nov 10 17:01:51 volumio systemd[1]: hciuart.service: Succeeded. Nov 10 17:01:51 volumio systemd[1]: Started Configure Bluetooth Modems connected by UART. Nov 10 17:01:51 volumio avahi-daemon[542]: Successfully called chroot(). Nov 10 17:01:51 volumio avahi-daemon[542]: Successfully dropped remaining capabilities. Nov 10 17:01:51 volumio wpa_supplicant[537]: Successfully initialized wpa_supplicant Nov 10 17:01:51 volumio avahi-daemon[542]: No service file found in /etc/avahi/services. Nov 10 17:01:51 volumio avahi-daemon[542]: Network interface enumeration completed. Nov 10 17:01:51 volumio avahi-daemon[542]: Server startup complete. Host name is volumio.local. Local service cookie is 1375703158. Nov 10 17:01:51 volumio sh[422]: eth0: soliciting a DHCP lease Nov 10 17:01:51 volumio dhcpcd[471]: eth0: soliciting a DHCP lease Nov 10 17:01:51 volumio systemd[1]: Started Raise network interfaces. Nov 10 17:01:51 volumio systemd[1]: Started Avahi mDNS/DNS-SD Stack. Nov 10 17:01:51 volumio systemd[1]: Started WPA supplicant. Nov 10 17:01:51 volumio systemd[1]: Reached target Network. Nov 10 17:01:51 volumio systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Nov 10 17:01:51 volumio sh[422]: eth0: soliciting an IPv6 router Nov 10 17:01:51 volumio dhcpcd[471]: eth0: soliciting an IPv6 router Nov 10 17:01:51 volumio systemd[1]: Starting Music Player Daemon... Nov 10 17:01:52 volumio systemd[1]: Starting OpenBSD Secure Shell server... Nov 10 17:01:52 volumio systemd[1]: Starting Network Time Service... Nov 10 17:01:52 volumio systemd[1]: Reached target Network is Online. Nov 10 17:01:52 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 10 17:01:52 volumio systemd[1]: Starting /etc/rc.local Compatibility... Nov 10 17:01:52 volumio sh[422]: eth0: offered 192.168.2.9 from 192.168.2.254 `Experiabox-V10' Nov 10 17:01:52 volumio dhcpcd[471]: eth0: offered 192.168.2.9 from 192.168.2.254 `Experiabox-V10' Nov 10 17:01:52 volumio dhcpcd[471]: eth0: probing address 192.168.2.9/24 Nov 10 17:01:52 volumio sh[422]: eth0: probing address 192.168.2.9/24 Nov 10 17:01:52 volumio systemd[1]: Starting LSB: Brings up/down network automatically... Nov 10 17:01:52 volumio systemd[1]: Starting Permit User Sessions... Nov 10 17:01:52 volumio systemd[1]: Starting Samba NMB Daemon... Nov 10 17:01:52 volumio systemd[1]: Starting Raspberry Pi bluetooth helper... Nov 10 17:01:52 volumio volumio-remote-updater[538]: Error: No active session Nov 10 17:01:52 volumio volumio-remote-updater[538]: [2023-11-10 17:01:52] [info] asio async_connect error: system:111 (Connection refused) Nov 10 17:01:52 volumio volumio-remote-updater[538]: [2023-11-10 17:01:52] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 10 17:01:52 volumio volumio-remote-updater[538]: [2023-11-10 17:01:52] [error] handle_connect error: Underlying Transport Error Nov 10 17:01:52 volumio systemd[1]: Started /etc/rc.local Compatibility. Nov 10 17:01:52 volumio systemd[1]: Started Permit User Sessions. Nov 10 17:01:52 volumio volumio[519]: Could not open config: /tmp/upmpdcli.conf Nov 10 17:01:52 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Nov 10 17:01:52 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 10 17:01:52 volumio systemd[1]: iptables.service: Succeeded. Nov 10 17:01:52 volumio systemd[1]: Starting Terminate Plymouth Boot Screen... Nov 10 17:01:52 volumio loadcpufreq[562]: Loading cpufreq kernel modules...done (none). Nov 10 17:01:52 volumio systemd[1]: Starting Hold until boot process finishes up... Nov 10 17:01:52 volumio ntpd[604]: ntpd 4.2.8p12@1.3728-o (1): Starting Nov 10 17:01:52 volumio ntpd[604]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Nov 10 17:01:52 volumio systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Nov 10 17:01:52 volumio systemd[1]: Started Network Time Service. Nov 10 17:01:52 volumio systemd[1]: Received SIGRTMIN+21 from PID 246 (plymouthd). Nov 10 17:01:52 volumio bthelper[618]: Raspberry Pi BDADDR already set Nov 10 17:01:52 volumio ntpd[656]: proto: precision = 1.458 usec (-19) Nov 10 17:01:52 volumio ntpd[656]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Nov 10 17:01:52 volumio ntpd[656]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2023-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 10 17:01:52 volumio ntpd[656]: Listen and drop on 0 v6wildcard [::]:123 Nov 10 17:01:52 volumio ntpd[656]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Nov 10 17:01:52 volumio ntpd[656]: Listen normally on 2 lo 127.0.0.1:123 Nov 10 17:01:52 volumio ntpd[656]: Listening on routing socket on fd #19 for interface updates Nov 10 17:01:52 volumio ntpd[656]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 10 17:01:52 volumio ntpd[656]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 10 17:01:52 volumio systemd[1]: plymouth-start.service: Succeeded. Nov 10 17:01:52 volumio systemd[1]: Started Raspberry Pi bluetooth helper. Nov 10 17:01:52 volumio systemd[1]: plymouth-quit.service: Succeeded. Nov 10 17:01:52 volumio systemd[1]: Started Terminate Plymouth Boot Screen. Nov 10 17:01:52 volumio systemd[1]: plymouth-quit-wait.service: Succeeded. Nov 10 17:01:52 volumio systemd[1]: Started Hold until boot process finishes up. Nov 10 17:01:52 volumio systemd[1]: Received SIGRTMIN+21 from PID 246 (n/a). Nov 10 17:01:52 volumio ifplugd(eth0)[672]: ifplugd 0.28 initializing. Nov 10 17:01:52 volumio ifplugd(eth0)[672]: Using interface eth0/B8:27:EB:EF:86:2F with driver (version: 6.1.58-v7+) Nov 10 17:01:52 volumio ifplugd(eth0)[672]: Using detection mode: SIOCETHTOOL Nov 10 17:01:52 volumio ifplugd(eth0)[672]: Initialization complete, link beat detected. Nov 10 17:01:53 volumio sshd[660]: Server listening on 0.0.0.0 port 22. Nov 10 17:01:53 volumio sshd[660]: Server listening on :: port 22. Nov 10 17:01:53 volumio systemd[1]: Started Getty on tty1. Nov 10 17:01:53 volumio systemd[1]: Reached target Login Prompts. Nov 10 17:01:53 volumio ifplugd(eth0)[672]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 10 17:01:53 volumio systemd[1]: Starting Bluetooth service... Nov 10 17:01:53 volumio systemd[1]: Starting LSB: set CPUFreq kernel parameters... Nov 10 17:01:53 volumio systemd[1]: Started OpenBSD Secure Shell server. Nov 10 17:01:53 volumio ifplugd(eth0)[672]: client: ifup: waiting for lock on /run/network/ifstate.eth0 Nov 10 17:01:53 volumio cpufrequtils[679]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Nov 10 17:01:53 volumio systemd[1]: Started LSB: set CPUFreq kernel parameters. Nov 10 17:01:53 volumio bluetoothd[676]: Bluetooth daemon 5.50 Nov 10 17:01:53 volumio bluetoothd[676]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Nov 10 17:01:53 volumio systemd[1]: Started Bluetooth service. Nov 10 17:01:53 volumio systemd[1]: Reached target Bluetooth. Nov 10 17:01:53 volumio bluetoothd[676]: Starting SDP server Nov 10 17:01:53 volumio bluetoothd[676]: Excluding (cli) sap Nov 10 17:01:53 volumio haveged[481]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Nov 10 17:01:53 volumio haveged[481]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Nov 10 17:01:53 volumio haveged[481]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99586 Nov 10 17:01:53 volumio haveged[481]: haveged: fills: 0, generated: 0 Nov 10 17:01:53 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Nov 10 17:01:53 volumio kernel: Bluetooth: BNEP filters: protocol multicast Nov 10 17:01:53 volumio kernel: Bluetooth: BNEP socket layer initialized Nov 10 17:01:53 volumio bluetoothd[676]: Bluetooth management interface 1.22 initialized Nov 10 17:01:53 volumio dbus-daemon[530]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=676 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Nov 10 17:01:53 volumio kernel: Bluetooth: MGMT ver 1.22 Nov 10 17:01:53 volumio bluetoothd[676]: Failed to set privacy: Rejected (0x0b) Nov 10 17:01:53 volumio ntpd[656]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 10 17:01:53 volumio systemd[1]: Starting Hostname Service... Nov 10 17:01:54 volumio dbus-daemon[530]: [system] Successfully activated service 'org.freedesktop.hostname1' Nov 10 17:01:54 volumio systemd[1]: Started Hostname Service. Nov 10 17:01:54 volumio nmbd[642]: [2023/11/10 17:01:54.522872, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Nov 10 17:01:54 volumio nmbd[642]: started asyncdns process 701 Nov 10 17:01:54 volumio nmbd[642]: [2023/11/10 17:01:54.529921, 0] ../lib/util/become_daemon.c:149(daemon_status) Nov 10 17:01:54 volumio nmbd[642]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Nov 10 17:01:54 volumio nmbd[642]: [2023/11/10 17:01:54.530139, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Nov 10 17:01:54 volumio nmbd[642]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Nov 10 17:01:54 volumio ntpd[656]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 10 17:01:54 volumio systemd[1]: systemd-rfkill.service: Succeeded. Nov 10 17:01:55 volumio wireless.js[522]: Cleaning previous... Nov 10 17:01:55 volumio sudo[709]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 10 17:01:55 volumio sudo[709]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:55 volumio sudo[709]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:55 volumio sudo[711]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 10 17:01:55 volumio sudo[711]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:55 volumio ntpd[656]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 10 17:01:55 volumio sudo[711]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:55 volumio wireless.js[522]: Stopped aP Nov 10 17:01:55 volumio sudo[718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 10 17:01:55 volumio sudo[718]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:55 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 10 17:01:55 volumio sudo[718]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:55 volumio sudo[720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Nov 10 17:01:55 volumio sudo[720]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:55 volumio sudo[720]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:56 volumio sudo[727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 10 17:01:56 volumio sudo[727]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:56 volumio sudo[727]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:56 volumio sudo[729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Nov 10 17:01:56 volumio sudo[729]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:56 volumio mpd[673]: Nov 10 17:01 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 10 17:01:56 volumio mpd[673]: Nov 10 17:01 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 10 17:01:56 volumio mpd[673]: Nov 10 17:01 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 10 17:01:56 volumio systemd[1]: Started Music Player Daemon. Nov 10 17:01:56 volumio sudo[729]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:56 volumio sudo[738]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Nov 10 17:01:56 volumio sudo[738]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:56 volumio sudo[738]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:56 volumio sudo[740]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Nov 10 17:01:56 volumio sudo[740]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:01:56 volumio ntpd[656]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 10 17:01:56 volumio sh[422]: eth0: leased 192.168.2.9 for 86400 seconds Nov 10 17:01:56 volumio dhcpcd[471]: eth0: leased 192.168.2.9 for 86400 seconds Nov 10 17:01:57 volumio avahi-daemon[542]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.2.9. Nov 10 17:01:57 volumio sh[422]: eth0: adding route to 192.168.2.0/24 Nov 10 17:01:57 volumio sh[422]: eth0: adding default route via 192.168.2.254 Nov 10 17:01:57 volumio avahi-daemon[542]: New relevant interface eth0.IPv4 for mDNS. Nov 10 17:01:57 volumio avahi-daemon[542]: Registering new address record for 192.168.2.9 on eth0.IPv4. Nov 10 17:01:57 volumio dhcpcd[471]: eth0: adding route to 192.168.2.0/24 Nov 10 17:01:57 volumio dhcpcd[471]: eth0: adding default route via 192.168.2.254 Nov 10 17:01:57 volumio sudo[740]: pam_unix(sudo:session): session closed for user root Nov 10 17:01:57 volumio avahi-daemon[542]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Nov 10 17:01:57 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 10 17:01:57 volumio avahi-daemon[542]: New relevant interface wlan0.IPv4 for mDNS. Nov 10 17:01:57 volumio avahi-daemon[542]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Nov 10 17:01:57 volumio sh[422]: forked to background, child pid 768 Nov 10 17:01:57 volumio dhcpcd[471]: forked to background, child pid 768 Nov 10 17:01:57 volumio systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server... Nov 10 17:01:57 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Nov 10 17:01:57 volumio dnsmasq[765]: dnsmasq: syntax check OK. Nov 10 17:01:57 volumio volumio-remote-updater[538]: [2023-11-10 17:01:57] [info] asio async_connect error: system:111 (Connection refused) Nov 10 17:01:57 volumio volumio-remote-updater[538]: [2023-11-10 17:01:57] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 10 17:01:57 volumio volumio-remote-updater[538]: [2023-11-10 17:01:57] [error] handle_connect error: Underlying Transport Error Nov 10 17:01:57 volumio hostapd[769]: Configuration file: /etc/hostapd/hostapd.conf Nov 10 17:01:57 volumio hostapd[769]: wlan0: Could not connect to kernel driver Nov 10 17:01:57 volumio hostapd[769]: Using interface wlan0 with hwaddr b8:27:eb:ba:d3:7a and ssid "Volumio-C3148" Nov 10 17:01:57 volumio dnsmasq[796]: started, version 2.80 cachesize 150 Nov 10 17:01:57 volumio dnsmasq[796]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile Nov 10 17:01:57 volumio dnsmasq-dhcp[796]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d Nov 10 17:01:57 volumio dnsmasq[796]: reading /etc/resolv.conf Nov 10 17:01:57 volumio dnsmasq[796]: using nameserver 192.168.2.254#53 Nov 10 17:01:57 volumio dnsmasq[796]: using nameserver 208.67.222.222#53 Nov 10 17:01:57 volumio dnsmasq[796]: using nameserver 208.67.220.220#53 Nov 10 17:01:57 volumio dnsmasq[796]: read /etc/hosts - 5 addresses Nov 10 17:01:57 volumio ifplugd(eth0)[672]: client: ifup: interface eth0 already configured Nov 10 17:01:57 volumio sh[422]: eth0=eth0 Nov 10 17:01:57 volumio ifplugd(eth0)[672]: Program executed successfully. Nov 10 17:01:57 volumio ifplugd[608]: Network Interface Plugging Daemon...start eth0...done. Nov 10 17:01:57 volumio systemd[1]: Started LSB: Brings up/down network automatically. Nov 10 17:01:57 volumio hostapd[769]: wlan0: interface state UNINITIALIZED->ENABLED Nov 10 17:01:57 volumio hostapd[769]: wlan0: AP-ENABLED Nov 10 17:01:57 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Nov 10 17:01:57 volumio systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server. Nov 10 17:01:57 volumio systemd[1]: Reached target Host and Network Name Lookups. Nov 10 17:01:57 volumio iwconfig[808]: Error for wireless request "Set Power Management" (8B2C) : Nov 10 17:01:57 volumio iwconfig[808]: SET failed on device wlan0 ; Invalid argument. Nov 10 17:01:57 volumio systemd[1]: wireless.service: Succeeded. Nov 10 17:01:57 volumio systemd[1]: Started Wireless Services. Nov 10 17:01:57 volumio systemd[1]: Started Volumio Backend Module. Nov 10 17:01:57 volumio systemd[1]: Started Volumio Cpu Tweaker. Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: Setting RT Priority for mpd Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: Setting MPD Affinity Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: pid 673's current affinity mask: f Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: pid 673's new affinity mask: 3 Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Nov 10 17:01:57 volumio volumio-cpu-tweak[810]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Nov 10 17:01:57 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Nov 10 17:01:57 volumio bthelper[618]: Changing power off succeeded Nov 10 17:01:58 volumio bthelper[618]: [CHG] Controller B8:27:EB:45:2C:85 Class: 0x0000041c Nov 10 17:01:58 volumio bthelper[618]: Changing power on succeeded Nov 10 17:01:58 volumio ntpd[656]: Listen normally on 3 eth0 192.168.2.9:123 Nov 10 17:01:58 volumio ntpd[656]: Listen normally on 4 wlan0 192.168.211.1:123 Nov 10 17:01:58 volumio ntpd[656]: new interface(s) found: waking up resolver Nov 10 17:01:59 volumio nmbd[642]: [2023/11/10 17:01:59.540146, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 10 17:01:59 volumio systemd[1]: Started Samba NMB Daemon. Nov 10 17:01:59 volumio nmbd[642]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 10 17:01:59 volumio systemd[1]: Starting Samba Winbind Daemon... Nov 10 17:01:59 volumio winbindd[833]: [2023/11/10 17:01:59.955351, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 10 17:01:59 volumio winbindd[833]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 10 17:01:59 volumio winbindd[833]: [2023/11/10 17:01:59.982668, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 10 17:01:59 volumio winbindd[833]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 10 17:01:59 volumio systemd[1]: Started Samba Winbind Daemon. Nov 10 17:02:00 volumio systemd[1]: Starting Samba SMB Daemon... Nov 10 17:02:00 volumio smbd[838]: [2023/11/10 17:02:00.625084, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 10 17:02:00 volumio smbd[838]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 10 17:02:00 volumio systemd[1]: Started Samba SMB Daemon. Nov 10 17:02:00 volumio systemd[1]: Reached target Multi-User System. Nov 10 17:02:00 volumio systemd[1]: Reached target Graphical Interface. Nov 10 17:02:00 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 10 17:02:00 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 10 17:02:00 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 10 17:02:00 volumio systemd[1]: Startup finished in 10.216s (kernel) + 17.711s (userspace) = 27.928s. Nov 10 17:02:00 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:00 volumio volumio[809]: info: ----- Volumio3 ---- Nov 10 17:02:00 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:00 volumio volumio[809]: info: ----- System startup ---- Nov 10 17:02:00 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:02 volumio volumio[809]: info: MYVOLUMIO Environment detected Nov 10 17:02:02 volumio volumio[809]: info: Plugin folders cleanup Nov 10 17:02:02 volumio volumio[809]: info: Scanning into folder /volumio/app/plugins/ Nov 10 17:02:02 volumio volumio[809]: info: Scanning category audio_interface Nov 10 17:02:02 volumio volumio[809]: info: Scanning category miscellanea Nov 10 17:02:02 volumio volumio[809]: info: Scanning category music_service Nov 10 17:02:02 volumio volumio[809]: info: Scanning category plugins.json Nov 10 17:02:02 volumio volumio[809]: info: Scanning category system_controller Nov 10 17:02:02 volumio volumio[809]: info: Scanning category user_interface Nov 10 17:02:02 volumio volumio[809]: info: Scanning into folder /data/plugins/ Nov 10 17:02:02 volumio volumio[809]: info: Scanning category audio_interface Nov 10 17:02:02 volumio volumio[809]: info: Scanning category music_service Nov 10 17:02:02 volumio volumio[809]: info: Scanning category system_hardware Nov 10 17:02:02 volumio volumio[809]: info: Scanning category user_interface Nov 10 17:02:02 volumio volumio[809]: info: Plugin folders cleanup completed Nov 10 17:02:02 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:02 volumio volumio[809]: info: ----- Core plugins startup ---- Nov 10 17:02:02 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:02 volumio volumio[809]: info: Loading plugins from folder /volumio/app/plugins/ Nov 10 17:02:02 volumio volumio[809]: info: Adding plugin upnp to MyMusic Plugins Nov 10 17:02:02 volumio volumio[809]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 10 17:02:02 volumio volumio[809]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 10 17:02:02 volumio volumio[809]: info: Loading plugins from folder /data/plugins/ Nov 10 17:02:02 volumio volumio[809]: info: Loading plugin "system"... Nov 10 17:02:02 volumio volumio[809]: info: Loading plugin "appearance"... Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "network"... Nov 10 17:02:04 volumio volumio[809]: info: Refreshing Cached IP Addresses Nov 10 17:02:04 volumio sudo[858]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 10 17:02:04 volumio sudo[858]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:04 volumio sudo[858]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "services"... Nov 10 17:02:04 volumio sudo[860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 10 17:02:04 volumio sudo[860]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "alsa_controller"... Nov 10 17:02:04 volumio sudo[860]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:04 volumio sudo[863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 10 17:02:04 volumio sudo[863]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:04 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "wizard"... Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "volumio_command_line_client"... Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "upnp"... Nov 10 17:02:04 volumio volumio[809]: info: [1699632124317] Starting Upmpd Daemon Nov 10 17:02:04 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "my_music"... Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "mpd"... Nov 10 17:02:04 volumio volumio[809]: info: Creating MPD Configuration file Nov 10 17:02:04 volumio volumio[809]: info: Loading plugin "upnp_browser"... Nov 10 17:02:04 volumio sudo[871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 10 17:02:04 volumio sudo[871]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:04 volumio sudo[871]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:04 volumio sudo[873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 10 17:02:04 volumio sudo[873]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:04 volumio systemd[1]: Stopping Music Player Daemon... Nov 10 17:02:04 volumio sudo[863]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:04 volumio volumio-remote-updater[538]: [2023-11-10 17:02:04] [connect] Successful connection Nov 10 17:02:05 volumio systemd[1]: mpd.service: Succeeded. Nov 10 17:02:05 volumio systemd[1]: Stopped Music Player Daemon. Nov 10 17:02:05 volumio systemd[1]: Starting Music Player Daemon... Nov 10 17:02:05 volumio volumio[809]: info: Loading plugin "networkfs"... Nov 10 17:02:05 volumio volumio[809]: info: Starting Udev Watcher for removable devices Nov 10 17:02:06 volumio volumio[809]: info: Ignoring mount for partition: boot Nov 10 17:02:06 volumio volumio[809]: info: Ignoring mount for partition: volumio Nov 10 17:02:06 volumio volumio[809]: info: Ignoring mount for partition: volumio_data Nov 10 17:02:06 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "alarm-clock"... Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "airplay_emulation"... Nov 10 17:02:06 volumio volumio[809]: info: Starting Shairport Sync Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "last_100"... Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "webradio"... Nov 10 17:02:06 volumio mpd[878]: Nov 10 17:02 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 10 17:02:06 volumio mpd[878]: Nov 10 17:02 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 10 17:02:06 volumio mpd[878]: Nov 10 17:02 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "i2s_dacs"... Nov 10 17:02:06 volumio systemd[1]: Started Music Player Daemon. Nov 10 17:02:06 volumio sudo[873]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "volumiodiscovery"... Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** For more information see Nov 10 17:02:06 volumio node[809]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 10 17:02:06 volumio volumio[809]: *** WARNING *** For more information see Nov 10 17:02:06 volumio node[809]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 10 17:02:06 volumio node[809]: *** WARNING *** For more information see Nov 10 17:02:06 volumio node[809]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 10 17:02:06 volumio node[809]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 10 17:02:06 volumio node[809]: *** WARNING *** For more information see Nov 10 17:02:06 volumio volumio[809]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 10 17:02:06 volumio volumio[809]: info: Discovery: Started advertising with name: Volumio Nov 10 17:02:06 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 10 17:02:06 volumio volumio[809]: info: Loading plugin "spop"... Nov 10 17:02:08 volumio volumio[809]: info: Loading plugin "gpio-buttons"... Nov 10 17:02:09 volumio volumio[809]: info: GPIO-Buttons initialized Nov 10 17:02:09 volumio volumio[809]: info: Loading plugin "now_playing"... Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "outputs"... Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "albumart"... Nov 10 17:02:11 volumio volumio[809]: info: Plugin example_plugin is not enabled Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "inputs"... Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "updater_comm"... Nov 10 17:02:11 volumio volumio[809]: info: Plugin mpdemulation is not enabled Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "rest_api"... Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "websocket"... Nov 10 17:02:11 volumio volumio[809]: info: Loading plugin "fusiondsp"... Nov 10 17:02:11 volumio volumio[809]: Forking 3 albumart workers Nov 10 17:02:12 volumio volumio[809]: info: Applying required configuration parameters for plugin fusiondsp Nov 10 17:02:12 volumio volumio[809]: info: Plugin motherearthradio is not enabled Nov 10 17:02:12 volumio volumio[809]: info: Loading plugin "ir_controller"... Nov 10 17:02:12 volumio volumio[809]: info: Applying required configuration parameters for plugin ir_controller Nov 10 17:02:12 volumio volumio[809]: Starting albumart workers Nov 10 17:02:12 volumio volumio[809]: Starting albumart workers Nov 10 17:02:12 volumio volumio[809]: Starting albumart workers Nov 10 17:02:12 volumio volumio[809]: info: Loading plugin "rotaryencoder2"... Nov 10 17:02:13 volumio volumio[809]: info: Loading plugin "touch_display"... Nov 10 17:02:14 volumio volumio[809]: info: Applying required configuration parameters for plugin touch_display Nov 10 17:02:14 volumio volumio[809]: info: Loading i18n strings for locale en Nov 10 17:02:14 volumio volumio[809]: Updating browse sources language Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::initPlayerControls Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 10 17:02:14 volumio volumio[809]: Express server listening on port 3000 Nov 10 17:02:14 volumio volumio[809]: [Metrics] WebUI: 14s 743.41ms Nov 10 17:02:14 volumio volumio[809]: info: CoreStateMachine::resetVolumioState Nov 10 17:02:14 volumio volumio[809]: info: CoreStateMachine::getcurrentVolume Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::volumioRetrievevolume Nov 10 17:02:14 volumio sudo[943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 10 17:02:14 volumio sudo[943]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:14 volumio sudo[943]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:14 volumio sudo[945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 10 17:02:14 volumio sudo[945]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:14 volumio sudo[945]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:14 volumio volumio[809]: info: MPD Permissions set Nov 10 17:02:14 volumio volumio[809]: info: VolumeController:: Volume=100 Mute =false Nov 10 17:02:14 volumio volumio[809]: info: CoreStateMachine::pushState Nov 10 17:02:14 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 10 17:02:14 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Nov 10 17:02:14 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Nov 10 17:02:14 volumio volumio[809]: info: CoreCommandRouter::volumioRetrievevolume Nov 10 17:02:14 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Nov 10 17:02:14 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 10 17:02:15 volumio volumio[809]: info: MPD running with PID878 Nov 10 17:02:15 volumio volumio[809]: ,establishing connection Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: Reloading queue from file Nov 10 17:02:15 volumio volumio[809]: error: updateQueue error: null Nov 10 17:02:15 volumio volumio[809]: info: Setting Device type: Raspberry PI Nov 10 17:02:15 volumio volumio[809]: info: CoreStateMachine::setRepeat null single undefined Nov 10 17:02:15 volumio volumio[809]: info: CoreStateMachine::pushState Nov 10 17:02:15 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 10 17:02:15 volumio volumio[809]: info: CoreStateMachine::setRandom null Nov 10 17:02:15 volumio volumio[809]: info: CoreStateMachine::pushState Nov 10 17:02:15 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 10 17:02:15 volumio volumio[809]: info: Completed loading Core Plugins Nov 10 17:02:15 volumio volumio[809]: info: Preparing to generate the ALSA configuration file Nov 10 17:02:15 volumio volumio[809]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 10 17:02:15 volumio volumio[809]: info: Reading ALSA contributions from plugins. Nov 10 17:02:15 volumio volumio[809]: error: updateQueue error: null Nov 10 17:02:15 volumio volumio[809]: info: VolumeController:: Volume=100 Mute =false Nov 10 17:02:15 volumio volumio[809]: info: CoreStateMachine::pushState Nov 10 17:02:15 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 10 17:02:15 volumio sudo[964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 10 17:02:15 volumio sudo[964]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:15 volumio volumio[809]: info: Discovery: adding 6fdb97ae-8ccf-447c-80fd-f6fd995e2fd0 Nov 10 17:02:15 volumio volumio[809]: info: Discovery: Found device Volumio Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:15 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:15 volumio volumio[809]: info: Discovery: this is already registered, 6fdb97ae-8ccf-447c-80fd-f6fd995e2fd0 Nov 10 17:02:15 volumio volumio[809]: info: Discovery: Found device Volumio Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:15 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:15 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Nov 10 17:02:15 volumio sudo[964]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:15 volumio volumio[809]: info: Upmpdcli Daemon Started Nov 10 17:02:15 volumio volumio[809]: info: Asound.conf file unchanged, so no further update is needed Nov 10 17:02:15 volumio volumio[809]: info: Output device has changed, restarting MPD Nov 10 17:02:15 volumio volumio[809]: info: Output device has changed, restarting Shairport Sync Nov 10 17:02:15 volumio sudo[968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:15 volumio sudo[968]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:15 volumio sudo[968]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:15 volumio sudo[970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 10 17:02:15 volumio sudo[970]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:15 volumio systemd[1]: Stopping Music Player Daemon... Nov 10 17:02:15 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 10 17:02:15 volumio systemd[1]: mpd.service: Succeeded. Nov 10 17:02:15 volumio systemd[1]: Stopped Music Player Daemon. Nov 10 17:02:15 volumio volumio[809]: info: ___________ START PLUGINS ___________ Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 10 17:02:15 volumio volumio[809]: info: [1699632135615] CoreMusicLibrary::Adding element Media Servers Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:15 volumio systemd[1]: Starting Music Player Daemon... Nov 10 17:02:15 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 10 17:02:15 volumio volumio[809]: info: [1699632135752] CoreMusicLibrary::Adding element Last_100 Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 10 17:02:15 volumio volumio[809]: info: [1699632135763] CoreMusicLibrary::Adding element Webradio Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:15 volumio volumio[809]: info: Creating Spotify config file Nov 10 17:02:15 volumio volumio[809]: info: GPIO-Buttons: Reading config and creating triggers... Nov 10 17:02:15 volumio volumio[809]: info: GPIO-Buttons: shutdown on pin 4 Nov 10 17:02:15 volumio volumio[809]: info: [now-playing] ConfigUpdater: config is up to date. Nov 10 17:02:15 volumio volumio[809]: info: Loading i18n strings for locale en Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:15 volumio volumio[809]: info: FusionDsp - mixtype--------------------- Hardware Nov 10 17:02:15 volumio volumio[809]: info: Loading i18n strings for locale en Nov 10 17:02:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:16 volumio volumio[809]: info: Loading i18n strings for locale en Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:16 volumio volumio[809]: info: Volumio Calling Home Nov 10 17:02:16 volumio volumio[809]: info: GPIO-Buttons started Nov 10 17:02:16 volumio volumio[809]: info: Preparing to generate the ALSA configuration file Nov 10 17:02:16 volumio sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Nov 10 17:02:16 volumio sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:16 volumio sudo[999]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:16 volumio sudo[1001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=23 pin_b=24 relative_axis=true steps-per-period=1 Nov 10 17:02:16 volumio sudo[1001]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:16 volumio sudo[1004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 10 17:02:16 volumio sudo[1004]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:16 volumio systemd[1]: Reloading. Nov 10 17:02:16 volumio volumio[809]: info: [now-playing] Fetching API key... Nov 10 17:02:16 volumio volumio[809]: info: [now-playing] App is listening on port 4004. Nov 10 17:02:16 volumio volumio[809]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Nov 10 17:02:16 volumio kernel: rotary-encoder rotary@17: gray Nov 10 17:02:16 volumio sudo[1001]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:16 volumio kernel: input: rotary@17 as /devices/platform/rotary@17/input/input2 Nov 10 17:02:16 volumio volumio[809]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 10 17:02:16 volumio volumio[809]: info: Reading ALSA contributions from plugins. Nov 10 17:02:16 volumio volumio[809]: error: Upnp client error: Error: This socket has been ended by the other party Nov 10 17:02:16 volumio volumio[809]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Nov 10 17:02:16 volumio volumio[809]: info: MPD Permissions set Nov 10 17:02:16 volumio volumio[809]: info: Spotify config file written Nov 10 17:02:16 volumio sudo[1034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 10 17:02:16 volumio sudo[1034]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:16 volumio systemd-udevd[1010]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 10 17:02:16 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 10 17:02:16 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Nov 10 17:02:16 volumio volumio[809]: info: Volumio called home Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:16 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:16 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 10 17:02:17 volumio volumio[809]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Nov 10 17:02:17 volumio volumio[809]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 10 17:02:17 volumio volumio[809]: SPOTIFY: BQDyeG8EyTvB6gRdYG6Q4zyBnDVCUFI4TuB3HKooMMKhRzV1uUHtQcdmItINyhAhs0m76NTgC7Fp-ZUgBvUDk3p5pJySP7t5_8Sp72ie2-zG929vR_A62ayGDCHoxGFJ-CtEsbGNCdE3Oq2VMVfu6OLsyFo8jgr-kKheuuZH3Yeu0D5uV1Mud9A8AJZ1s0iMC17jJN86treI2ImMkuDuLJlL0_6lCIxLjA5kUG-FnutNGbq6tHW-Vg Nov 10 17:02:17 volumio volumio[809]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 10 17:02:17 volumio volumio[809]: info: New Spotify access token = BQDyeG8EyTvB6gRdYG6Q4zyBnDVCUFI4TuB3HKooMMKhRzV1uUHtQcdmItINyhAhs0m76NTgC7Fp-ZUgBvUDk3p5pJySP7t5_8Sp72ie2-zG929vR_A62ayGDCHoxGFJ-CtEsbGNCdE3Oq2VMVfu6OLsyFo8jgr-kKheuuZH3Yeu0D5uV1Mud9A8AJZ1s0iMC17jJN86treI2ImMkuDuLJlL0_6lCIxLjA5kUG-FnutNGbq6tHW-Vg Nov 10 17:02:17 volumio volumio[809]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 10 17:02:17 volumio volumio[809]: info: Starting Shairport Sync Nov 10 17:02:17 volumio volumio[809]: info: Starting Shairport Sync Nov 10 17:02:17 volumio volumio[809]: info: Starting Shairport Sync Nov 10 17:02:17 volumio sudo[1041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 10 17:02:17 volumio sudo[1041]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio sudo[1045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 10 17:02:17 volumio sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio sudo[1046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 10 17:02:17 volumio sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Nov 10 17:02:17 volumio volumio[809]: info: Asound.conf file unchanged, so no further update is needed Nov 10 17:02:17 volumio volumio[809]: info: Output device has changed, restarting MPD Nov 10 17:02:17 volumio volumio[809]: info: Output device has changed, restarting Shairport Sync Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:17 volumio sudo[1050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 10 17:02:17 volumio sudo[1050]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio mpd[985]: Nov 10 17:02 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 10 17:02:17 volumio mpd[985]: Nov 10 17:02 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 10 17:02:17 volumio mpd[985]: Nov 10 17:02 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 10 17:02:17 volumio sudo[1050]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio sudo[1052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 10 17:02:17 volumio sudo[1052]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 10 17:02:17 volumio volumio[809]: info: ir_controller: LIRC correctly updated. Nov 10 17:02:17 volumio volumio[809]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Nov 10 17:02:17 volumio systemd[1]: Started Music Player Daemon. Nov 10 17:02:17 volumio sudo[1004]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio sudo[970]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio volumio[809]: info: ir_controller: Raspberry Pi revision code: a02082 Nov 10 17:02:17 volumio volumio[809]: info: MPD Permissions set Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:17 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:17 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:17 volumio volumio[809]: info: touch_display: systemctl daemon-reload succeeded. Nov 10 17:02:17 volumio systemd[1]: Stopping Music Player Daemon... Nov 10 17:02:17 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 10 17:02:17 volumio sudo[1065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Nov 10 17:02:17 volumio sudo[1065]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio systemd[1]: Started go-librespot Daemon. Nov 10 17:02:17 volumio go-librespot[1067]: Librespot-go daemon starting... Nov 10 17:02:17 volumio systemd[1]: systemd-fsckd.service: Succeeded. Nov 10 17:02:17 volumio sudo[1034]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 10 17:02:17 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 10 17:02:17 volumio systemd[1]: mpd.service: Succeeded. Nov 10 17:02:17 volumio systemd[1]: Stopped Music Player Daemon. Nov 10 17:02:17 volumio systemd[1]: Started Volumio Kiosk. Nov 10 17:02:17 volumio sudo[1065]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio systemd[1]: Starting Music Player Daemon... Nov 10 17:02:17 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio sudo[1046]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio sudo[1081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Nov 10 17:02:17 volumio sudo[1081]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:17 volumio sudo[1041]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio sudo[1045]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio sudo[1081]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:17 volumio volumio[809]: error: MPD error: Error: write EPIPE Nov 10 17:02:17 volumio volumio[809]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Nov 10 17:02:17 volumio volumio[809]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Nov 10 17:02:17 volumio volumio[809]: info: touch_display: Volumio Kiosk started Nov 10 17:02:17 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:17 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:18 volumio volumio[809]: info: Completed starting Core Plugins Nov 10 17:02:18 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:18 volumio volumio[809]: info: ----- MyVolumio plugins startup ---- Nov 10 17:02:18 volumio volumio[809]: info: ------------------------------------------- Nov 10 17:02:18 volumio volumio[809]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 10 17:02:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:18 volumio volumio[809]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Nov 10 17:02:18 volumio volumio[809]: info: FusionDsp loaded Nov 10 17:02:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 10 17:02:18 volumio sudo[1125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Nov 10 17:02:18 volumio volumio[809]: info: FusionDsp - Reporting Fusion DSP Enabled Nov 10 17:02:18 volumio volumio[809]: info: Adding Signal Path Element [object Object] Nov 10 17:02:18 volumio volumio[809]: info: Adding fusiondspeq DSP Signal Path Element Nov 10 17:02:18 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:18 volumio volumio[809]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Nov 10 17:02:18 volumio volumio[809]: info: Shairport-Sync Started Nov 10 17:02:18 volumio startx[1077]: X.Org X Server 1.20.4 Nov 10 17:02:18 volumio startx[1077]: X Protocol Version 11, Revision 0 Nov 10 17:02:18 volumio startx[1077]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Nov 10 17:02:18 volumio startx[1077]: Current Operating System: Linux volumio 6.1.58-v7+ #1690 SMP Tue Oct 17 15:35:01 BST 2023 armv7l Nov 10 17:02:18 volumio startx[1077]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1280 bcm2708_fb.fbheight=400 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 Nov 10 17:02:18 volumio startx[1077]: Build Date: 04 April 2023 07:50:56AM Nov 10 17:02:18 volumio startx[1077]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Nov 10 17:02:18 volumio startx[1077]: Current version of pixman: 0.36.0 Nov 10 17:02:18 volumio startx[1077]: Before reporting problems, check http://wiki.x.org Nov 10 17:02:18 volumio startx[1077]: to make sure that you have the latest version. Nov 10 17:02:18 volumio startx[1077]: Markers: (--) probed, (**) from config file, (==) default setting, Nov 10 17:02:18 volumio startx[1077]: (++) from command line, (!!) notice, (II) informational, Nov 10 17:02:18 volumio startx[1077]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Nov 10 17:02:18 volumio startx[1077]: (==) Log file: "/var/log/Xorg.0.log", Time: Fri Nov 10 17:02:18 2023 Nov 10 17:02:18 volumio sudo[1125]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:18 volumio volumio[809]: Error adding Membership: Error: addMembership EINVAL Nov 10 17:02:18 volumio volumio[809]: info: Shairport-Sync Started Nov 10 17:02:18 volumio volumio[809]: info: Shairport-Sync Started Nov 10 17:02:18 volumio systemd[1]: Started FusionDsp Daemon. Nov 10 17:02:18 volumio sudo[1125]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:18 volumio startx[1077]: (==) Using config directory: "/etc/X11/xorg.conf.d" Nov 10 17:02:18 volumio startx[1077]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Nov 10 17:02:18 volumio volumio[809]: info: Starting Shairport Sync Nov 10 17:02:18 volumio go-librespot[1067]: time="2023-11-10T17:02:18+01:00" level=info msg="generated new device id: 3e402d85a8464b5c992eabf17d2724cc1e49f38b" Nov 10 17:02:18 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Nov 10 17:02:18 volumio go-librespot[1067]: time="2023-11-10T17:02:18+01:00" level=debug msg="stored credentials found for michelbinkys" Nov 10 17:02:18 volumio sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 10 17:02:18 volumio sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:18 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 10 17:02:18 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 10 17:02:18 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 10 17:02:18 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 10 17:02:18 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 10 17:02:18 volumio sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=25 gpio_pull=up Nov 10 17:02:18 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 10 17:02:18 volumio sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:18 volumio sudo[1134]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:18 volumio kernel: Registered IR keymap rc-rc6-mce Nov 10 17:02:18 volumio sudo[1138]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:18 volumio kernel: IR RC6 protocol handler initialized Nov 10 17:02:18 volumio kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0 Nov 10 17:02:18 volumio kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Nov 10 17:02:18 volumio kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@19/rc/rc0/input3 Nov 10 17:02:18 volumio sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Nov 10 17:02:18 volumio sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:18 volumio volumio[809]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Nov 10 17:02:18 volumio volumio[809]: info: ir_controller: Overlay gpio-ir gpio_pin=25 gpio_pull=up loaded. Nov 10 17:02:18 volumio volumio[809]: info: Shairport-Sync Started Nov 10 17:02:18 volumio systemd[1]: Starting lircd(8) initialization helper tool... Nov 10 17:02:18 volumio sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Nov 10 17:02:18 volumio sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:19 volumio systemd-udevd[1010]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 10 17:02:19 volumio systemd-logind[529]: Watching system buttons on /dev/input/event2 (gpio_ir_recv) Nov 10 17:02:19 volumio volumio[809]: SPOTIFY: User informations: {"display_name":"michelbinkys","external_urls":{"spotify":"https://open.spotify.com/user/michelbinkys"},"href":"https://api.spotify.com/v1/users/michelbinkys","id":"michelbinkys","images":[],"type":"user","uri":"spotify:user:michelbinkys","followers":{"href":null,"total":2},"country":"NL","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"mm.alofs605@kpnmail.nl"} Nov 10 17:02:19 volumio volumio[809]: info: Spotify Successfully logged in Nov 10 17:02:19 volumio volumio[809]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 10 17:02:19 volumio volumio[809]: info: [1699632139045] CoreMusicLibrary::Adding element Spotify Nov 10 17:02:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:19 volumio volumio[809]: Cannot find translation for source Spotify Nov 10 17:02:19 volumio volumio[809]: info: FusionDsp - nulleq: Nov 10 17:02:19 volumio volumio[809]: type: Conv Nov 10 17:02:19 volumio lircd-setup[1156]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in future versions. Use ConfigParser directly instead. Nov 10 17:02:19 volumio lircd-setup[1156]: parser = configparser.SafeConfigParser() Nov 10 17:02:19 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 10 17:02:19 volumio go-librespot[1067]: time="2023-11-10T17:02:19+01:00" level=debug msg="obtained new client token: AADAPEh0yWrQGSAGAfK0OUCalp6PgLHaIgkb+Hn1mkSNpBl+g82yhCDJxNvv45YhS+ZVGHY0tpx2NCv98HJRcyzxs+oEM8/nVe+ItivDVF0tBoIkCbgV2JTspcX2H3YnLIZcYZCksO0wqO7POYsmK39uIyhkYdT3kmrmLZKM4p2SLEUZYUMREL4SwNuwWr1Z4SLJg1G5HtCas1desGkP7dUhzbWsJUf9nqDp6qP4zJmmyGzH/REWyFsomJ/F" Nov 10 17:02:19 volumio systemd[1]: lircd-setup.service: Succeeded. Nov 10 17:02:19 volumio systemd[1]: Started lircd(8) initialization helper tool. Nov 10 17:02:19 volumio systemd[1]: Starting Flexible IR remote input/output application support... Nov 10 17:02:19 volumio volumio[809]: info: [now-playing] OpenWeatherMap API key obtained. Nov 10 17:02:19 volumio go-librespot[1067]: time="2023-11-10T17:02:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: lircd: Opening log, level: Info Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Version: lircd 0.10.1 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: System info: Linux volumio 6.1.58-v7+ #1690 SMP Tue Oct 17 15:35:01 BST 2023 armv7l GNU/Linux Nov 10 17:02:19 volumio go-librespot[1067]: time="2023-11-10T17:02:19+01:00" level=debug msg="completed keyexchange" Nov 10 17:02:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 10 17:02:19 volumio volumio[809]: info: Discovery: Getting this device information Nov 10 17:02:19 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 10 17:02:19 volumio volumio-remote-updater[538]: [2023-11-10 17:02:19] [connect] Successful connection Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: Initial device: /dev/lirc0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: 'lirc' written to protocols file /sys/class/rc/rc0/protocols Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: Initial device: /dev/lirc0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: [lirc] protocol is enabled Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: driver: default Nov 10 17:02:19 volumio lircd[1165]: lircd-0.10.1[1165]: Info: lircd: Opening log, level: Info Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: output: /var/run/lirc/lircd Nov 10 17:02:19 volumio lircd[1165]: lircd-0.10.1[1165]: Notice: Using systemd fd Nov 10 17:02:19 volumio lircd[1165]: lircd-0.10.1[1165]: Warning: Running as root Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: nodaemon: 1 Nov 10 17:02:19 volumio lircd[1165]: lircd-0.10.1[1165]: Info: Using remote: /etc/lirc/lircd-custom.conf. Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: logfile: syslog Nov 10 17:02:19 volumio lircd[1165]: lircd-0.10.1[1165]: Notice: lircd(default) ready, using /var/run/lirc/lircd Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: immediate-init: 0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: permission: 666 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: driver-options: Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: listen: 0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: connect: (null) Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: userelease: 0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: effective_user: (null) Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: release_suffix: _EVUP Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: allow_simulate: 0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: repeat_max: 600 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: configfile: /etc/lirc/lircd.conf Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Options: dynamic_codes: (null) Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Current driver: default Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Driver API version: 3 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Driver version: 0.10.0 Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: lircd: Opening log, level: Info Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: Using systemd fd Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Warning: Running as root Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Info: Using remote: /etc/lirc/lircd-custom.conf. Nov 10 17:02:19 volumio lircd-0.10.1[1165]: Notice: lircd(default) ready, using /var/run/lirc/lircd Nov 10 17:02:19 volumio systemd[1]: Started Flexible IR remote input/output application support. Nov 10 17:02:20 volumio sudo[1151]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:20 volumio sudo[1158]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:20 volumio volumio[809]: info: ir_controller: systemctl restart lircd.service succeeded. Nov 10 17:02:20 volumio volumio[809]: info: ir_controller: systemctl restart lircd.service succeeded. Nov 10 17:02:20 volumio mpd[1126]: Nov 10 17:02 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 10 17:02:20 volumio mpd[1126]: Nov 10 17:02 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 10 17:02:20 volumio mpd[1126]: Nov 10 17:02 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 10 17:02:20 volumio volumio-remote-updater[538]: [2023-11-10 17:02:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1699632139 101 Nov 10 17:02:20 volumio systemd[1]: Started Music Player Daemon. Nov 10 17:02:20 volumio sudo[1052]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:20 volumio volumio[809]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 6 Nov 10 17:02:20 volumio sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Nov 10 17:02:20 volumio sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="completed challenge" Nov 10 17:02:20 volumio sudo[1169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Nov 10 17:02:20 volumio sudo[1169]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="authenticated as michelbinkys" Nov 10 17:02:20 volumio systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Nov 10 17:02:20 volumio systemd[1]: Stopping Handle events from IR remotes decoded by lircd(8)... Nov 10 17:02:20 volumio sudo[1171]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:20 volumio systemd[1]: irexec.service: Main process exited, code=killed, status=15/TERM Nov 10 17:02:20 volumio systemd[1]: irexec.service: Succeeded. Nov 10 17:02:20 volumio systemd[1]: Stopped Handle events from IR remotes decoded by lircd(8). Nov 10 17:02:20 volumio systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Nov 10 17:02:20 volumio sudo[1169]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="authenticated as michelbinkys" Nov 10 17:02:20 volumio lircd[1165]: lircd-0.10.1[1165]: Notice: accepted new client on /var/run/lirc/lircd Nov 10 17:02:20 volumio lircd-0.10.1[1165]: Notice: accepted new client on /var/run/lirc/lircd Nov 10 17:02:20 volumio lircd[1165]: lircd-0.10.1[1165]: Info: [lirc] protocol is enabled Nov 10 17:02:20 volumio lircd-0.10.1[1165]: Info: [lirc] protocol is enabled Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 10 17:02:20 volumio volumio[809]: error: updateQueue error: null Nov 10 17:02:20 volumio volumio[809]: info: ir_controller: systemctl restart irexec.service succeeded. Nov 10 17:02:20 volumio volumio[809]: info: ir_controller: systemctl restart irexec.service succeeded. Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="dealer connection opened" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="received connection id: YWI1YTZkZjQtNTE0OC00NmY2LWIwYzgtN2RiNmFiNGU4YzBmK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLWZkeHcuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwK0U5QzdFNEQzNENDNjM5QkJGQjZDQUIzMEY4ODUzOEQ5MzRCNTQ4NkUwNjBCRjM4QjNBQ0Q3MkM2MkI5RDc2OUI=" Nov 10 17:02:20 volumio volumio[809]: error: Upnp client error: Error: This socket has been ended by the other party Nov 10 17:02:20 volumio go-librespot[1067]: time="2023-11-10T17:02:20+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 10 17:02:20 volumio volumio[966]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 10 17:02:21 volumio volumio[809]: info: go-librespot daemon successfully initialized Nov 10 17:02:21 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 10 17:02:24 volumio volumio[809]: info: Initializing connection to go-librespot Websocket Nov 10 17:02:24 volumio go-librespot[1067]: time="2023-11-10T17:02:24+01:00" level=debug msg="new websocket client" Nov 10 17:02:24 volumio volumio[809]: info: Connection to go-librespot Websocket established Nov 10 17:02:24 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Nov 10 17:02:26 volumio volumio[966]: ......................................++++ Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin bluetooth to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin multiroom to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin metavolumio to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin cd_controller to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 10 17:02:26 volumio volumio[809]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 10 17:02:28 volumio volumio[809]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 10 17:02:28 volumio volumio[809]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 10 17:02:28 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:28 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:28 volumio volumio[809]: info: Starting MyVolumio Remote Streaming Endpoints Nov 10 17:02:28 volumio volumio[809]: info: MyVolumio login type: Token Nov 10 17:02:28 volumio volumio[809]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 10 17:02:28 volumio volumio[809]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 10 17:02:29 volumio volumio[809]: info: Starting Streaming Service Transparent Proxy Nov 10 17:02:29 volumio volumio[809]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 10 17:02:29 volumio volumio[809]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 10 17:02:29 volumio volumio[809]: info: Streaming services startup Nov 10 17:02:29 volumio volumio[809]: info: Starting Streaming Daemon Nov 10 17:02:29 volumio sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 10 17:02:29 volumio sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:29 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:30 volumio volumio[809]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 10 17:02:30 volumio volumio[809]: info: Getting Spotify volume Nov 10 17:02:30 volumio volumio[809]: error: Cannot start Volumio Streaming Daemon Nov 10 17:02:30 volumio volumio[809]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 10 17:02:30 volumio volumio[809]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 10 17:02:30 volumio volumio[809]: info: Spotify volume: 100 Nov 10 17:02:30 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Nov 10 17:02:30 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:30 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:30 volumio volumio[809]: error: MyVolumio Custom Token format not valid, refreshing it Nov 10 17:02:30 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 10 17:02:31 volumio volumio[809]: info: MyVolumio login type: Token Nov 10 17:02:31 volumio volumio[809]: STREAMING PROXY: Starting server on port 3245 Nov 10 17:02:31 volumio volumio[809]: Node JS runtime: 14 Nov 10 17:02:31 volumio volumio[809]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 10 17:02:32 volumio volumio[809]: info: MyVolumio token set successfully Nov 10 17:02:32 volumio volumio[809]: info: MYVOLUMIO: Adding device Nov 10 17:02:32 volumio volumio[809]: info: MYVOLUMIO: Evaluating Server Nov 10 17:02:33 volumio volumio[809]: info: MyVolumio status changed Nov 10 17:02:33 volumio volumio[809]: info: Streaming services startup Nov 10 17:02:33 volumio volumio[809]: info: Starting Streaming Daemon Nov 10 17:02:33 volumio volumio[809]: info: Removing browser output: myVolumio user plan is not superstar Nov 10 17:02:33 volumio volumio[809]: info: Removing audio output: Nov 10 17:02:33 volumio volumio[809]: info: Stoppping Tunnel 1 Nov 10 17:02:33 volumio sudo[1416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 10 17:02:33 volumio sudo[1414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 10 17:02:33 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:33 volumio sudo[1414]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:02:33 volumio sudo[1414]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:33 volumio volumio[809]: error: Cannot start Volumio Streaming Daemon Nov 10 17:02:33 volumio volumio[809]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 10 17:02:33 volumio volumio[809]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 10 17:02:33 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root Nov 10 17:02:33 volumio volumio[809]: info: Remote SSH Stopped Nov 10 17:02:33 volumio volumio[809]: info: Setting Geolocation for MyVolumio to eu5 Nov 10 17:02:33 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:33 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:33 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:33 volumio volumio[809]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 10 17:02:33 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 8 Nov 10 17:02:34 volumio volumio[809]: info: Updating MyVolumio device info Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:34 volumio volumio[809]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Nov 10 17:02:34 volumio volumio[809]: info: Listing playlists Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue Nov 10 17:02:34 volumio volumio[809]: info: CoreStateMachine::getQueue Nov 10 17:02:34 volumio volumio[809]: info: CorePlayQueue::getQueue Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::volumioGetVisibleSources Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:02:34 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:34 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:35 volumio volumio[809]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 10 17:02:37 volumio volumio[966]: ...............................................................................++++ Nov 10 17:02:37 volumio volumio[966]: e is 65537 (0x010001) Nov 10 17:02:37 volumio volumio[966]: writing RSA key Nov 10 17:02:37 volumio volumio[809]: info: MYVOLUMIO: Adding device Nov 10 17:02:37 volumio volumio[809]: info: MYVOLUMIO: Evaluating Server Nov 10 17:02:38 volumio volumio[809]: info: Setting Geolocation for MyVolumio to eu5 Nov 10 17:02:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:39 volumio volumio[809]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 10 17:02:39 volumio volumio[809]: info: Updating MyVolumio device info Nov 10 17:02:39 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:39 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:39 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:39 volumio volumio[809]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 10 17:02:43 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 10 17:02:43 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Nov 10 17:02:43 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:02:43 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 10 17:02:46 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 10 17:02:46 volumio volumio-remote-updater[538]: No test mode Nov 10 17:02:46 volumio volumio-remote-updater[538]: No alpha test mode Nov 10 17:02:46 volumio volumio[809]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 10 17:02:46 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::volumioGetBrowseSources Nov 10 17:02:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 10 17:02:50 volumio volumio[809]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 10 17:02:50 volumio volumio[809]: info: Completed starting MyVolumio Plugin Nov 10 17:02:50 volumio volumio[809]: info: BOOT COMPLETED Nov 10 17:02:50 volumio volumio[809]: [Metrics] CommandRouter: 49s 39.37ms Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::volumiosetStartupVolume Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 10 17:02:50 volumio volumio[809]: info: VolumeController:: Setting startup Volume 100 Nov 10 17:02:50 volumio volumio[809]: info: VolumeController::SetAlsaVolume100 Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::Close All Modals sent Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::Close All Modals sent Nov 10 17:02:50 volumio volumio[809]: info: CoreStateMachine::pushState Nov 10 17:02:50 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:02:50 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 10 17:02:50 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 10 17:02:50 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 10 17:02:50 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 10 17:02:51 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 10 17:02:51 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 10 17:02:51 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 10 17:02:51 volumio volumio[809]: info: FusionDsp - nulleq: Nov 10 17:02:51 volumio volumio[809]: type: Conv Nov 10 17:02:51 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 10 17:02:58 volumio ntpd[656]: Soliciting pool server 185.80.247.36 Nov 10 17:02:59 volumio ntpd[656]: Soliciting pool server 51.15.20.83 Nov 10 17:02:59 volumio ntpd[656]: Soliciting pool server 188.226.159.244 Nov 10 17:03:00 volumio ntpd[656]: Soliciting pool server 86.80.166.233 Nov 10 17:03:00 volumio ntpd[656]: Soliciting pool server 5.255.99.180 Nov 10 17:03:00 volumio ntpd[656]: Soliciting pool server 129.250.35.251 Nov 10 17:03:00 volumio ntpd[656]: Soliciting pool server 158.101.221.122 Nov 10 17:03:01 volumio ntpd[656]: Soliciting pool server 185.51.192.61 Nov 10 17:03:01 volumio ntpd[656]: Soliciting pool server 37.1.205.111 Nov 10 17:03:01 volumio ntpd[656]: Soliciting pool server 95.211.120.4 Nov 10 17:03:01 volumio ntpd[656]: Soliciting pool server 83.137.149.135 Nov 10 17:03:02 volumio ntpd[656]: Soliciting pool server 23.94.219.146 Nov 10 17:03:02 volumio ntpd[656]: Soliciting pool server 5.200.6.34 Nov 10 17:03:02 volumio ntpd[656]: Soliciting pool server 87.233.197.123 Nov 10 17:03:03 volumio ntpd[656]: Soliciting pool server 2a01:1b1:1::36 Nov 10 17:03:04 volumio sudo[1636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 10 17:03:04 volumio sudo[1634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 10 17:03:04 volumio sudo[1636]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:03:04 volumio sudo[1634]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:03:04 volumio sudo[1636]: pam_unix(sudo:session): session closed for user root Nov 10 17:03:04 volumio sudo[1634]: pam_unix(sudo:session): session closed for user root Nov 10 17:03:05 volumio sudo[1640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 10 17:03:05 volumio sudo[1640]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:03:05 volumio sudo[1640]: pam_unix(sudo:session): session closed for user root Nov 10 17:03:05 volumio sudo[1643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 10 17:03:05 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 10 17:03:05 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Nov 10 17:03:05 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.2.9 from 192.168.2.11 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36 Total Clients: 10 Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetVisibleSources Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:03:05 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 10 17:03:05 volumio volumio[809]: info: Received Get System Info Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 10 17:03:05 volumio volumio[809]: info: Discovery: Getting this device information Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:03:05 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:03:05 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:03:05 volumio volumio[809]: info: Listing playlists Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 10 17:03:05 volumio volumio[809]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 10 17:03:06 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:03:06 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 10 17:03:07 volumio volumio[809]: info: Received Get System Info Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 10 17:03:07 volumio volumio[809]: info: Discovery: Getting this device information Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 10 17:03:07 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 10 17:03:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 10 17:03:08 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue Nov 10 17:03:08 volumio volumio[809]: info: CoreStateMachine::getQueue Nov 10 17:03:08 volumio volumio[809]: info: CorePlayQueue::getQueue Nov 11 11:19:17 volumio ntpd[656]: receive: Unexpected origin timestamp 0xe8f8d2bc.c8319494 does not match aorg 0000000000.00000000 from server@185.51.192.61 xmt 0xe8f9d3a5.9be57fd2 Nov 11 11:19:17 volumio ntpd[656]: receive: Unexpected origin timestamp 0xe8f8d2bc.c82fbd02 does not match aorg 0000000000.00000000 from server@83.137.149.135 xmt 0xe8f9d3a5.9bfebb91 Nov 11 11:19:17 volumio ntpd[656]: receive: Unexpected origin timestamp 0xe8f8d2bc.c834cf3f does not match aorg 0000000000.00000000 from server@86.80.166.233 xmt 0xe8f9d3a5.9bf638f4 Nov 11 11:19:17 volumio ntpd[656]: receive: Unexpected origin timestamp 0xe8f8d2bc.c8366f57 does not match aorg 0000000000.00000000 from server@185.80.247.36 xmt 0xe8f9d3a5.9c13419e Nov 11 11:19:17 volumio ntpd[656]: receive: Unexpected origin timestamp 0xe8f8d2bc.c8281160 does not match aorg 0000000000.00000000 from server@37.1.205.111 xmt 0xe8f9d3a5.9c4ad794 Nov 11 11:19:17 volumio systemd[1]: Starting Daily apt download activities... Nov 11 11:19:17 volumio systemd[1]: Starting Daily man-db regeneration... Nov 11 11:19:18 volumio systemd[1]: man-db.service: Succeeded. Nov 11 11:19:18 volumio systemd[1]: Started Daily man-db regeneration. Nov 11 11:19:18 volumio volumio[809]: info: Discovery: A device disappeared from network Nov 11 11:19:18 volumio volumio[809]: info: Discovery: Device volumio disappeared from network Nov 11 11:19:18 volumio volumio[809]: info: Discovery: A device disappeared from network Nov 11 11:19:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Nov 11 11:19:18 volumio volumio[809]: info: Discovery: adding 6fdb97ae-8ccf-447c-80fd-f6fd995e2fd0 Nov 11 11:19:18 volumio volumio[809]: info: Discovery: Found device Volumio Nov 11 11:19:18 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:18 volumio volumio[809]: info: Discovery: this is already registered, 6fdb97ae-8ccf-447c-80fd-f6fd995e2fd0 Nov 11 11:19:18 volumio volumio[809]: info: Discovery: Found device Volumio Nov 11 11:19:18 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:18 volumio volumio[809]: info: Preload queue cleared Nov 11 11:19:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 11 11:19:19 volumio volumio[809]: info: Received Get System Info Nov 11 11:19:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 11 11:19:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 11 11:19:19 volumio volumio[809]: info: Discovery: Getting this device information Nov 11 11:19:19 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 11 11:19:21 volumio systemd[1]: apt-daily.service: Succeeded. Nov 11 11:19:21 volumio systemd[1]: Started Daily apt download activities. Nov 11 11:19:21 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Nov 11 11:19:22 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Nov 11 11:19:22 volumio systemd[1]: Started Daily apt upgrade and clean activities. Nov 11 11:19:28 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.2.9 from 192.168.2.11 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36 Total Clients: 10 Nov 11 11:19:28 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:28 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:28 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue Nov 11 11:19:28 volumio volumio[809]: info: CoreStateMachine::getQueue Nov 11 11:19:28 volumio volumio[809]: info: CorePlayQueue::getQueue Nov 11 11:19:28 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Nov 11 11:19:29 volumio go-librespot[1067]: time="2023-11-11T11:19:29+01:00" level=error msg="did not receive last pong from dealer, 30s passed" Nov 11 11:19:29 volumio go-librespot[1067]: time="2023-11-11T11:19:29+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusServiceRestart and reason = \"\"" Nov 11 11:19:29 volumio go-librespot[1067]: time="2023-11-11T11:19:29+01:00" level=debug msg="re-established dealer connection" Nov 11 11:19:29 volumio go-librespot[1067]: time="2023-11-11T11:19:29+01:00" level=debug msg="received connection id: OTgyODcwOWYtMjk0Ny00MTU5LWEzNzctYTQyNDg4NThkNzdlK2RlYWxlcit0Y3A6Ly9ndWMzLWRlYWxlci1hLXJoeGYuZ3VjMy5zcG90aWZ5Lm5ldDo1NzAwKzcxMTQwNDZDRDE0MUNBOTAzNzBCMUI4ODcxQjNFRTBGOTQ2NjkxMUJENjA4QTAzMDVCMkJFMEE3MkQ0RjI2QUI=" Nov 11 11:19:29 volumio go-librespot[1067]: time="2023-11-11T11:19:29+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 11 11:19:36 volumio volumio[809]: info: CALLMETHOD: system_controller system enableLiveLog true Nov 11 11:19:36 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog Nov 11 11:19:36 volumio volumio[809]: info: Launching a new LiveLog session Nov 11 11:19:53 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.2.9 from 192.168.2.11 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36 Total Clients: 10 Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::volumioGetVisibleSources Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:54 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue Nov 11 11:19:54 volumio volumio[809]: info: CoreStateMachine::getQueue Nov 11 11:19:54 volumio volumio[809]: info: CorePlayQueue::getQueue Nov 11 11:19:54 volumio volumio[809]: info: Listing playlists Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 11 11:19:54 volumio volumio[809]: info: Received Get System Info Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 11 11:19:54 volumio volumio[809]: info: Discovery: Getting this device information Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:54 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:54 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 11 11:19:54 volumio volumio[809]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 11 11:19:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 11 11:19:55 volumio volumio[809]: info: Received Get System Info Nov 11 11:19:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 11 11:19:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 11 11:19:55 volumio volumio[809]: info: Discovery: Getting this device information Nov 11 11:19:55 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:55 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 11 11:19:56 volumio volumio[809]: info: Received Get System Info Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 11 11:19:56 volumio volumio[809]: info: Discovery: Getting this device information Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:19:56 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 11 11:19:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Nov 11 11:19:56 volumio volumio[809]: info: Preload queue cleared Nov 11 11:19:58 volumio volumio[809]: info: Preload queue cleared Nov 11 11:19:58 volumio volumio[809]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::ClearQueue Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::stop Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::saveQueue Nov 11 11:19:58 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::addQueueItems Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::addQueueItems Nov 11 11:19:58 volumio volumio[809]: info: Preload queue cleared Nov 11 11:19:58 volumio volumio[809]: info: Adding Item to queue: http://mp3-128.streamthejazzgroove.com/?referer=tunein.com Nov 11 11:19:58 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Nov 11 11:19:58 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::saveQueue Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Nov 11 11:19:58 volumio volumio[809]: info: CoreCommandRouter::volumioPlay Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::play index 0 Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::stop Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::play index undefined Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:58 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Nov 11 11:19:58 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:19:58 volumio volumio[809]: info: [1699697998871] ControllerWebradio::clearAddPlayTrack Nov 11 11:19:58 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand stop Nov 11 11:19:58 volumio volumio[809]: info: sendMpdCommand stop took 14 milliseconds Nov 11 11:19:58 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand clear Nov 11 11:19:58 volumio volumio[809]: info: Nov 11 11:19:58 volumio volumio[809]: ---------------------------- MPD announces system playlist update Nov 11 11:19:58 volumio volumio[809]: info: Ignoring MPD Status Update Nov 11 11:19:58 volumio volumio[809]: info: sendMpdCommand clear took 6 milliseconds Nov 11 11:19:58 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand load "http://mp3-128.streamthejazzgroove.com/?referer=tunein.com" Nov 11 11:19:58 volumio volumio[809]: error: updateQueue error: null Nov 11 11:19:58 volumio volumio[809]: info: ------------------------------ 12ms Nov 11 11:20:00 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand add "http://mp3-128.streamthejazzgroove.com/?referer=tunein.com" Nov 11 11:20:00 volumio volumio[809]: info: Nov 11 11:20:00 volumio volumio[809]: ---------------------------- MPD announces system playlist update Nov 11 11:20:00 volumio volumio[809]: info: Ignoring MPD Status Update Nov 11 11:20:00 volumio volumio[809]: info: sendMpdCommand add "http://mp3-128.streamthejazzgroove.com/?referer=tunein.com" took 3 milliseconds Nov 11 11:20:00 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 11 11:20:00 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand play Nov 11 11:20:00 volumio volumio[809]: info: ------------------------------ 8ms Nov 11 11:20:00 volumio volumio[809]: info: sendMpdCommand play took 6 milliseconds Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces state update: player Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::getState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces state update: player Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand status took 43 milliseconds Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::getState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand status took 5 milliseconds Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::pushState Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:01 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:01 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"?referer=tunein.com","artist":null,"album":null,"uri":"http://mp3-128.streamthejazzgroove.com/?referer=tunein.com","trackType":"com"} Nov 11 11:20:01 volumio volumio[809]: verbose: CURRENT POSITION 0 Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Nov 11 11:20:01 volumio volumio[809]: info: ------------------------------ 66ms Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand playlistinfo took 12 milliseconds Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::pushState Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:01 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:01 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"?referer=tunein.com","artist":null,"album":null,"uri":"http://mp3-128.streamthejazzgroove.com/?referer=tunein.com","trackType":"com"} Nov 11 11:20:01 volumio volumio[809]: verbose: CURRENT POSITION 0 Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Nov 11 11:20:01 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:01 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:01 volumio volumio[809]: info: ------------------------------ 82ms Nov 11 11:20:01 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:01 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:01 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:01 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:01 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:01 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces system playlist update Nov 11 11:20:01 volumio volumio[809]: info: Ignoring MPD Status Update Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces state update: player Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::getState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces system playlist update Nov 11 11:20:01 volumio volumio[809]: info: Ignoring MPD Status Update Nov 11 11:20:01 volumio volumio[809]: info: Nov 11 11:20:01 volumio volumio[809]: ---------------------------- MPD announces state update: player Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::getState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status Nov 11 11:20:01 volumio volumio[809]: info: ------------------------------ 8ms Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand status took 6 milliseconds Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 11 11:20:01 volumio volumio[809]: info: ------------------------------ 11ms Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand status took 8 milliseconds Nov 11 11:20:01 volumio volumio[809]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseState Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 11 11:20:01 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo Nov 11 11:20:01 volumio volumio[809]: info: ControllerMpd::pushState Nov 11 11:20:01 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:01 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:01 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Donald Byrd - House Of The Rising Sun","artist":"Jazz Groove Mix 2 (Free FLAC)","album":null,"uri":"http://mp3-128.streamthejazzgroove.com/?referer=tunein.com","trackType":"com"} Nov 11 11:20:01 volumio volumio[809]: verbose: CURRENT POSITION 0 Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Nov 11 11:20:01 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Nov 11 11:20:02 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:02 volumio volumio[809]: info: ------------------------------ 71ms Nov 11 11:20:02 volumio volumio[809]: info: sendMpdCommand playlistinfo took 57 milliseconds Nov 11 11:20:02 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo Nov 11 11:20:02 volumio volumio[809]: info: ControllerMpd::pushState Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:02 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:02 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Donald Byrd - House Of The Rising Sun","artist":"Jazz Groove Mix 2 (Free FLAC)","album":null,"uri":"http://mp3-128.streamthejazzgroove.com/?referer=tunein.com","trackType":"com"} Nov 11 11:20:02 volumio volumio[809]: verbose: CURRENT POSITION 0 Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Nov 11 11:20:02 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:02 volumio volumio[809]: info: ------------------------------ 179ms Nov 11 11:20:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:02 volumio volumio[809]: type: Conv Nov 11 11:20:02 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:02 volumio volumio[809]: type: Conv Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:02 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:03 volumio volumio[809]: type: Conv Nov 11 11:20:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:03 volumio volumio[809]: type: Conv Nov 11 11:20:03 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:03 volumio volumio[809]: type: Conv Nov 11 11:20:03 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:03 volumio volumio[809]: type: Conv Nov 11 11:20:03 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:03 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:04 volumio kernel: rc rc0: two consecutive events of type space Nov 11 11:20:11 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 11 11:20:11 volumio volumio[809]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 11 11:20:11 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 11 11:20:11 volumio volumio[809]: info: Received Get System Version Nov 11 11:20:11 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=debug msg="handling transfer player command from f85dcaf5d0db81ae74f22844a53b0f102aa98f00" Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=debug msg="loading track spotify:track:6LhdrSN5DFsTfuGwKRv69o (paused: true, position: 1828ms)" Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=trace msg="emitting websocket event: will_play" Nov 11 11:20:28 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","play_origin":"playlist"}} Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6LhdrSN5DFsTfuGwKRv69o" Nov 11 11:20:28 volumio go-librespot[1067]: time="2023-11-11T11:20:28+01:00" level=debug msg="requested aes key for file debd338be9f7dd372391e5a0d74c9e512c0c9bf4, gid: 6LhdrSN5DFsTfuGwKRv69o" Nov 11 11:20:29 volumio go-librespot[1067]: time="2023-11-11T11:20:29+01:00" level=debug msg="fetched first chunk of 7, total size is 3237784 bytes" Nov 11 11:20:29 volumio go-librespot[1067]: time="2023-11-11T11:20:29+01:00" level=trace msg="seek to 1828ms (diff: 45ms, samples: 80614, bytes: 66427)" Nov 11 11:20:29 volumio go-librespot[1067]: time="2023-11-11T11:20:29+01:00" level=debug msg="fetched chunk 3/6, size: 524288" Nov 11 11:20:29 volumio go-librespot[1067]: time="2023-11-11T11:20:29+01:00" level=debug msg="fetched chunk 2/6, size: 524288" Nov 11 11:20:29 volumio go-librespot[1067]: time="2023-11-11T11:20:29+01:00" level=debug msg="fetched chunk 1/6, size: 524288" Nov 11 11:20:42 volumio volumio[809]: info: CoreCommandRouter::volumioStop Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::stop Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Nov 11 11:20:42 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:42 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:42 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:42 volumio volumio[809]: info: CoreStateMachine::serviceStop Nov 11 11:20:42 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:42 volumio volumio[809]: info: CoreCommandRouter::serviceStop Nov 11 11:20:42 volumio volumio[809]: info: [1699698042640] ControllerWebradio::stop Nov 11 11:20:42 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand stop Nov 11 11:20:42 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:42 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:42 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:42 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 11 11:20:43 volumio volumio[809]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Nov 11 11:20:43 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 11 11:20:43 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:43 volumio volumio[809]: type: Conv Nov 11 11:20:43 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:43 volumio go-librespot[1067]: ALSA lib /home/pi/volumio-hook-plugin/src/pcm_volumiohook.c:144:(snd_pcm_volumiohook_close) PCM close called for fusiondsphook Nov 11 11:20:43 volumio go-librespot[1067]: time="2023-11-11T11:20:43+01:00" level=info msg="loaded track \"Burning Skies\" (uri: spotify:track:6LhdrSN5DFsTfuGwKRv69o, paused: true, position: 1828ms, duration: 85255ms)" Nov 11 11:20:43 volumio volumio[809]: info: Nov 11 11:20:43 volumio volumio[809]: ---------------------------- MPD announces state update: player Nov 11 11:20:43 volumio volumio[809]: info: sendMpdCommand stop took 1201 milliseconds Nov 11 11:20:43 volumio volumio[809]: info: ControllerMpd::getState Nov 11 11:20:43 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status Nov 11 11:20:43 volumio volumio[809]: info: sendMpdCommand status took 2 milliseconds Nov 11 11:20:43 volumio volumio[809]: verbose: ControllerMpd::parseState Nov 11 11:20:43 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 11 11:20:43 volumio volumio[809]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 11 11:20:43 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo Nov 11 11:20:43 volumio volumio[809]: info: ControllerMpd::pushState Nov 11 11:20:43 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:43 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:43 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:43 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:43 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:43 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:43 volumio volumio[809]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Nov 11 11:20:43 volumio volumio[809]: info: ------------------------------ 85ms Nov 11 11:20:43 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:43 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:43 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=trace msg="emitting websocket event: metadata" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=trace msg="emitting websocket event: active" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="sending successful reply for delaer request" Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","name":"Burning Skies","artist_names":["Introwa"],"album_name":"Burning Men","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02281f1851d1fb155785954bdc","position":1828,"duration":85255}} Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: received: {"type":"active","data":null} Nov 11 11:20:44 volumio volumio[809]: info: Aligning Spotify Volume to Volumio Volume Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:20:44 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Nov 11 11:20:44 volumio volumio[809]: info: Setting Spotify Volume from Volumio: 100 Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=trace msg="emitting websocket event: paused" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="handling resume player command from f85dcaf5d0db81ae74f22844a53b0f102aa98f00" Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","play_origin":"playlist"}} Nov 11 11:20:44 volumio volumio[809]: info: Spotify is playing in volatile mode Nov 11 11:20:44 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: UNSET VOLATILE Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: {"status":"stop","position":0,"title":"Eric Reed - Pure Imagination","artist":"","albumart":"/albumart","uri":"http://mp3-128.streamthejazzgroove.com/?referer=tunein.com","trackType":"webradio","seek":314,"samplerate":"","bitdepth":"","channels":0,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"webradio","updatedb":false,"volatile":false,"service":"webradio"} Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: {"status":"pause","service":"spop","title":"Burning Skies","artist":"Introwa","album":"Burning Men","albumart":"https://i.scdn.co/image/ab67616d00001e02281f1851d1fb155785954bdc","uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","trackType":"spotify","seek":1828,"duration":85,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=trace msg="seek to 1828ms (diff: 45ms, samples: 80614, bytes: 66427)" Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:44 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="resume track at 1598ms" Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="sending successful reply for delaer request" Nov 11 11:20:44 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:44 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:20:44 volumio go-librespot[1067]: time="2023-11-11T11:20:44+01:00" level=trace msg="emitting websocket event: playing" Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","play_origin":"playlist"}} Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Burning Skies","artist":"Introwa","album":"Burning Men","albumart":"https://i.scdn.co/image/ab67616d00001e02281f1851d1fb155785954bdc","uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","trackType":"spotify","seek":1828,"duration":85,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:44 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:20:44 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:44 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:44 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:44 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:44 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:44 volumio volumio[809]: type: Conv Nov 11 11:20:44 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:45 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:20:45 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Burning Skies","artist":"Introwa","album":"Burning Men","albumart":"https://i.scdn.co/image/ab67616d00001e02281f1851d1fb155785954bdc","uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","trackType":"spotify","seek":1828,"duration":85,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:20:45 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:20:45 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:20:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:20:45 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:20:45 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:20:45 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:20:45 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:45 volumio volumio[809]: type: Conv Nov 11 11:20:45 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:45 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:45 volumio volumio[809]: type: Conv Nov 11 11:20:45 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:20:46 volumio volumio[809]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Nov 11 11:20:46 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/volume Nov 11 11:20:46 volumio go-librespot[1067]: time="2023-11-11T11:20:46+01:00" level=debug msg="update volume to 65535/65535" Nov 11 11:20:46 volumio go-librespot[1067]: time="2023-11-11T11:20:46+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Nov 11 11:20:46 volumio go-librespot[1067]: time="2023-11-11T11:20:46+01:00" level=trace msg="emitting websocket event: volume" Nov 11 11:20:46 volumio volumio[809]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Nov 11 11:20:46 volumio volumio[809]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Nov 11 11:20:46 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:20:46 volumio volumio[809]: type: Conv Nov 11 11:20:46 volumio volumio[809]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 11 11:20:56 volumio go-librespot[1067]: time="2023-11-11T11:20:56+01:00" level=debug msg="fetched chunk 4/6, size: 524288" Nov 11 11:21:09 volumio go-librespot[1067]: time="2023-11-11T11:21:09+01:00" level=debug msg="fetched chunk 5/6, size: 524288" Nov 11 11:21:23 volumio go-librespot[1067]: time="2023-11-11T11:21:23+01:00" level=debug msg="fetched chunk 6/6, size: 92056" Nov 11 11:22:10 volumio go-librespot[1067]: ALSA lib /home/pi/volumio-hook-plugin/src/pcm_volumiohook.c:144:(snd_pcm_volumiohook_close) PCM close called for fusiondsphook Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=trace msg="emitting websocket event: not_playing" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="loading track spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1 (paused: false, position: 0ms)" Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:6LhdrSN5DFsTfuGwKRv69o","play_origin":"playlist"}} Nov 11 11:22:10 volumio volumio[809]: error: Failed to decode event: not_playing Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=trace msg="emitting websocket event: will_play" Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","play_origin":"playlist"}} Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="requested aes key for file 1751d4402d410a5f830a72429f3d414eb2a5d560, gid: 3CQ1uqSXCkmRWtHMsK9UJ1" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="fetched first chunk of 7, total size is 3532716 bytes" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=info msg="loaded track \"Kadıköy\" (uri: spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1, paused: false, position: 0ms, duration: 94909ms)" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=trace msg="emitting websocket event: metadata" Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","name":"Kadıköy","artist_names":["YėY"],"album_name":"Heading Home","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02cc3169be37e58acdae18d6f7","position":0,"duration":94909}} Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="fetched chunk 1/6, size: 524288" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:22:10 volumio go-librespot[1067]: time="2023-11-11T11:22:10+01:00" level=trace msg="emitting websocket event: playing" Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","play_origin":"playlist"}} Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:22:10 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Kadıköy","artist":"YėY","album":"Heading Home","albumart":"https://i.scdn.co/image/ab67616d00001e02cc3169be37e58acdae18d6f7","uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","trackType":"spotify","seek":0,"duration":94,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:22:10 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:22:10 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:22:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:22:10 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:22:11 volumio go-librespot[1067]: time="2023-11-11T11:22:11+01:00" level=debug msg="fetched chunk 2/6, size: 524288" Nov 11 11:22:11 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:22:11 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:22:11 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:22:11 volumio go-librespot[1067]: time="2023-11-11T11:22:11+01:00" level=debug msg="fetched chunk 3/6, size: 524288" Nov 11 11:22:11 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:22:11 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Kadıköy","artist":"YėY","album":"Heading Home","albumart":"https://i.scdn.co/image/ab67616d00001e02cc3169be37e58acdae18d6f7","uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","trackType":"spotify","seek":0,"duration":94,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:22:11 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:22:11 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:22:11 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:22:11 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:22:11 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:22:11 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:22:12 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:22:12 volumio volumio[809]: type: Conv Nov 11 11:22:12 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:22:12 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:22:12 volumio volumio[809]: type: Conv Nov 11 11:22:12 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:22:24 volumio go-librespot[1067]: time="2023-11-11T11:22:24+01:00" level=debug msg="fetched chunk 4/6, size: 524288" Nov 11 11:22:38 volumio go-librespot[1067]: time="2023-11-11T11:22:38+01:00" level=debug msg="fetched chunk 5/6, size: 524288" Nov 11 11:22:52 volumio go-librespot[1067]: time="2023-11-11T11:22:52+01:00" level=debug msg="fetched chunk 6/6, size: 386988" Nov 11 11:23:47 volumio go-librespot[1067]: ALSA lib /home/pi/volumio-hook-plugin/src/pcm_volumiohook.c:144:(snd_pcm_volumiohook_close) PCM close called for fusiondsphook Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=trace msg="emitting websocket event: not_playing" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="loading track spotify:track:6cwaFjcyv2x8pO8v11YpQd (paused: false, position: 0ms)" Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:3CQ1uqSXCkmRWtHMsK9UJ1","play_origin":"playlist"}} Nov 11 11:23:47 volumio volumio[809]: error: Failed to decode event: not_playing Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=trace msg="emitting websocket event: will_play" Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","play_origin":"playlist"}} Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6cwaFjcyv2x8pO8v11YpQd" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="requested aes key for file f51bf64b30e03b5c344cd2d06378747160966363, gid: 6cwaFjcyv2x8pO8v11YpQd" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="fetched first chunk of 12, total size is 5908712 bytes" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=info msg="loaded track \"Introspection - Radio version\" (uri: spotify:track:6cwaFjcyv2x8pO8v11YpQd, paused: false, position: 0ms, duration: 131478ms)" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=trace msg="emitting websocket event: metadata" Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","name":"Introspection - Radio version","artist_names":["Miss Babayaga DJ","DJ Josh Blackwell"],"album_name":"Tulum After Hours","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b980a6764b7b19c7edf13cc3","position":0,"duration":131478}} Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:23:47 volumio go-librespot[1067]: time="2023-11-11T11:23:47+01:00" level=trace msg="emitting websocket event: playing" Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","play_origin":"playlist"}} Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Introspection - Radio version","artist":"Miss Babayaga DJ, DJ Josh Blackwell","album":"Tulum After Hours","albumart":"https://i.scdn.co/image/ab67616d00001e02b980a6764b7b19c7edf13cc3","uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","trackType":"spotify","seek":0,"duration":131,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:23:47 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:23:47 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:23:47 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:23:47 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:23:47 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:23:48 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:23:48 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:23:48 volumio go-librespot[1067]: time="2023-11-11T11:23:48+01:00" level=debug msg="fetched chunk 3/11, size: 524288" Nov 11 11:23:48 volumio go-librespot[1067]: time="2023-11-11T11:23:48+01:00" level=debug msg="fetched chunk 2/11, size: 524288" Nov 11 11:23:48 volumio go-librespot[1067]: time="2023-11-11T11:23:48+01:00" level=debug msg="fetched chunk 1/11, size: 524288" Nov 11 11:23:48 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:23:48 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Introspection - Radio version","artist":"Miss Babayaga DJ, DJ Josh Blackwell","album":"Tulum After Hours","albumart":"https://i.scdn.co/image/ab67616d00001e02b980a6764b7b19c7edf13cc3","uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","trackType":"spotify","seek":1000,"duration":131,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:23:48 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:23:48 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:23:48 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:23:48 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:23:48 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:23:48 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:23:48 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:23:49 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:23:49 volumio volumio[809]: type: Conv Nov 11 11:23:49 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:23:49 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:23:49 volumio volumio[809]: type: Conv Nov 11 11:23:49 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:23:59 volumio go-librespot[1067]: time="2023-11-11T11:23:59+01:00" level=debug msg="fetched chunk 4/11, size: 524288" Nov 11 11:24:10 volumio go-librespot[1067]: time="2023-11-11T11:24:10+01:00" level=debug msg="fetched chunk 5/11, size: 524288" Nov 11 11:24:21 volumio go-librespot[1067]: time="2023-11-11T11:24:21+01:00" level=debug msg="fetched chunk 6/11, size: 524288" Nov 11 11:24:33 volumio go-librespot[1067]: time="2023-11-11T11:24:33+01:00" level=debug msg="fetched chunk 7/11, size: 524288" Nov 11 11:24:46 volumio go-librespot[1067]: time="2023-11-11T11:24:46+01:00" level=debug msg="fetched chunk 8/11, size: 524288" Nov 11 11:24:58 volumio go-librespot[1067]: time="2023-11-11T11:24:58+01:00" level=debug msg="fetched chunk 9/11, size: 524288" Nov 11 11:25:09 volumio go-librespot[1067]: time="2023-11-11T11:25:09+01:00" level=debug msg="fetched chunk 10/11, size: 524288" Nov 11 11:25:21 volumio go-librespot[1067]: time="2023-11-11T11:25:21+01:00" level=debug msg="fetched chunk 11/11, size: 141544" Nov 11 11:26:01 volumio go-librespot[1067]: ALSA lib /home/pi/volumio-hook-plugin/src/pcm_volumiohook.c:144:(snd_pcm_volumiohook_close) PCM close called for fusiondsphook Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=trace msg="emitting websocket event: not_playing" Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=debug msg="loading track spotify:track:1UGiRoaDeRLleqmAzMNImV (paused: false, position: 0ms)" Nov 11 11:26:01 volumio volumio[809]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:6cwaFjcyv2x8pO8v11YpQd","play_origin":"playlist"}} Nov 11 11:26:01 volumio volumio[809]: error: Failed to decode event: not_playing Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=trace msg="emitting websocket event: will_play" Nov 11 11:26:01 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1UGiRoaDeRLleqmAzMNImV","play_origin":"playlist"}} Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1UGiRoaDeRLleqmAzMNImV" Nov 11 11:26:01 volumio go-librespot[1067]: time="2023-11-11T11:26:01+01:00" level=debug msg="requested aes key for file 8a8490e5204cb31be2eb88906a63b0880c4739c9, gid: 1UGiRoaDeRLleqmAzMNImV" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="fetched first chunk of 26, total size is 13151636 bytes" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=info msg="loaded track \"Tango With Edda\" (uri: spotify:track:1UGiRoaDeRLleqmAzMNImV, paused: false, position: 0ms, duration: 315692ms)" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=trace msg="emitting websocket event: metadata" Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1UGiRoaDeRLleqmAzMNImV","name":"Tango With Edda","artist_names":["JPattersson","Lui Mafuta"],"album_name":"Tango With Edda","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a57adb933fef9b4541070413","position":0,"duration":315692}} Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="fetched chunk 1/25, size: 524288" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="fetched chunk 3/25, size: 524288" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=trace msg="emitting websocket event: playing" Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1UGiRoaDeRLleqmAzMNImV","play_origin":"playlist"}} Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Tango With Edda","artist":"JPattersson, Lui Mafuta","album":"Tango With Edda","albumart":"https://i.scdn.co/image/ab67616d00001e02a57adb933fef9b4541070413","uri":"spotify:track:1UGiRoaDeRLleqmAzMNImV","trackType":"spotify","seek":0,"duration":315,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:26:02 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:26:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:26:02 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 11 11:26:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:26:02 volumio go-librespot[1067]: time="2023-11-11T11:26:02+01:00" level=debug msg="fetched chunk 2/25, size: 524288" Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:26:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:26:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"Tango With Edda","artist":"JPattersson, Lui Mafuta","album":"Tango With Edda","albumart":"https://i.scdn.co/image/ab67616d00001e02a57adb933fef9b4541070413","uri":"spotify:track:1UGiRoaDeRLleqmAzMNImV","trackType":"spotify","seek":0,"duration":315,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 11 11:26:02 volumio volumio[809]: info: CoreCommandRouter::servicePushState Nov 11 11:26:02 volumio volumio[809]: info: CoreStateMachine::pushState Nov 11 11:26:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Nov 11 11:26:02 volumio volumio[809]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 11 11:26:02 volumio volumio[809]: error: FusionDsp - File size not found in array! Nov 11 11:26:02 volumio volumio[809]: info: FusionDsp - Nulleq applied Nov 11 11:26:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:26:03 volumio volumio[809]: type: Conv Nov 11 11:26:03 volumio volumio[809]: error: FusionDsp - WebSocket error: [object Object] Nov 11 11:26:03 volumio volumio[809]: info: FusionDsp - nulleq: Nov 11 11:26:03 volumio volumio[809]: type: Conv Nov 11 11:26:03 volumio volumio[809]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 11 11:26:15 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.2.9 from 192.168.2.11 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/119.0.0.0 Safari/537.36 Total Clients: 10 Nov 11 11:26:15 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Nov 11 11:26:15 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue Nov 11 11:26:15 volumio volumio[809]: info: CoreStateMachine::getQueue Nov 11 11:26:15 volumio volumio[809]: info: CorePlayQueue::getQueue Nov 11 11:26:15 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Nov 11 11:26:16 volumio go-librespot[1067]: time="2023-11-11T11:26:16+01:00" level=debug msg="fetched chunk 4/25, size: 524288" Nov 11 11:26:29 volumio go-librespot[1067]: time="2023-11-11T11:26:29+01:00" level=debug msg="fetched chunk 5/25, size: 524288" Nov 11 11:26:32 volumio volumio[809]: info: CALLMETHOD: system_controller system sendBugReport [object Object] Nov 11 11:26:32 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , sendBugReport Nov 11 11:26:32 volumio sudo[1924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig Nov 11 11:26:32 volumio sudo[1924]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 11 11:26:32 volumio sudo[1924]: pam_unix(sudo:session): session closed for user root Nov 11 11:26:40 volumio sudo[1982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl -p 7 Nov 11 11:26:40 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root by (uid=0)