-- Logs begin at Thu 2019-02-14 07:11:59 -03, end at Sun 2024-08-18 23:16:08 -03. -- Aug 18 23:15:28 volumio1 kernel: raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-17T15:42:39, variant start Aug 18 23:15:28 volumio1 kernel: raspberrypi-firmware soc:firmware: Firmware hash is 30f0c5e4d076da3ab4f341d88e7d505760b93ad7 Aug 18 23:15:28 volumio1 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Aug 18 23:15:28 volumio1 kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 Aug 18 23:15:28 volumio1 kernel: SCSI subsystem initialized Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver usbfs Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver hub Aug 18 23:15:28 volumio1 kernel: usbcore: registered new device driver usb Aug 18 23:15:28 volumio1 kernel: usb_phy_generic phy: supply vcc not found, using dummy regulator Aug 18 23:15:28 volumio1 kernel: pps_core: LinuxPPS API ver. 1 registered Aug 18 23:15:28 volumio1 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Aug 18 23:15:28 volumio1 kernel: PTP clock support registered Aug 18 23:15:28 volumio1 kernel: clocksource: Switched to clocksource arch_sys_counter Aug 18 23:15:28 volumio1 kernel: VFS: Disk quotas dquot_6.6.0 Aug 18 23:15:28 volumio1 kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Aug 18 23:15:28 volumio1 kernel: FS-Cache: Loaded Aug 18 23:15:28 volumio1 kernel: CacheFiles: Loaded Aug 18 23:15:28 volumio1 kernel: NET: Registered PF_INET protocol family Aug 18 23:15:28 volumio1 kernel: IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear) Aug 18 23:15:28 volumio1 kernel: tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear) Aug 18 23:15:28 volumio1 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Aug 18 23:15:28 volumio1 kernel: TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear) Aug 18 23:15:28 volumio1 kernel: TCP bind hash table entries: 4096 (order: 4, 65536 bytes, linear) Aug 18 23:15:28 volumio1 kernel: TCP: Hash tables configured (established 4096 bind 4096) Aug 18 23:15:28 volumio1 kernel: UDP hash table entries: 256 (order: 1, 8192 bytes, linear) Aug 18 23:15:28 volumio1 kernel: UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear) Aug 18 23:15:28 volumio1 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Aug 18 23:15:28 volumio1 kernel: RPC: Registered named UNIX socket transport module. Aug 18 23:15:28 volumio1 kernel: RPC: Registered udp transport module. Aug 18 23:15:28 volumio1 kernel: RPC: Registered tcp transport module. Aug 18 23:15:28 volumio1 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Aug 18 23:15:28 volumio1 kernel: Trying to unpack rootfs image as initramfs... Aug 18 23:15:28 volumio1 kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available Aug 18 23:15:28 volumio1 kernel: Freeing initrd memory: 14316K Aug 18 23:15:28 volumio1 kernel: Initialise system trusted keyrings Aug 18 23:15:28 volumio1 kernel: workingset: timestamp_bits=14 max_order=17 bucket_order=3 Aug 18 23:15:28 volumio1 kernel: zbud: loaded Aug 18 23:15:28 volumio1 kernel: NFS: Registering the id_resolver key type Aug 18 23:15:28 volumio1 kernel: Key type id_resolver registered Aug 18 23:15:28 volumio1 kernel: Key type id_legacy registered Aug 18 23:15:28 volumio1 kernel: nfs4filelayout_init: NFSv4 File Layout Driver Registering... Aug 18 23:15:28 volumio1 kernel: nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... Aug 18 23:15:28 volumio1 kernel: Key type asymmetric registered Aug 18 23:15:28 volumio1 kernel: Asymmetric key parser 'x509' registered Aug 18 23:15:28 volumio1 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Aug 18 23:15:28 volumio1 kernel: io scheduler mq-deadline registered Aug 18 23:15:28 volumio1 kernel: io scheduler kyber registered Aug 18 23:15:28 volumio1 kernel: bcm2708_fb soc:fb: FB found 1 display(s) Aug 18 23:15:28 volumio1 kernel: Console: switching to colour frame buffer device 80x30 Aug 18 23:15:28 volumio1 kernel: bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480 Aug 18 23:15:28 volumio1 kernel: bcm2835-rng 3f104000.rng: hwrng registered Aug 18 23:15:28 volumio1 kernel: vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB) Aug 18 23:15:28 volumio1 kernel: brd: module loaded Aug 18 23:15:28 volumio1 kernel: loop: module loaded Aug 18 23:15:28 volumio1 kernel: Loading iSCSI transport class v2.0-870. Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver lan78xx Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver smsc95xx Aug 18 23:15:28 volumio1 kernel: dwc_otg: version 3.00a 10-AUG-2012 (platform bus) Aug 18 23:15:28 volumio1 kernel: Core Release: 2.80a Aug 18 23:15:28 volumio1 kernel: Setting default values for core params Aug 18 23:15:28 volumio1 kernel: Finished setting default values for core params Aug 18 23:15:28 volumio1 kernel: Using Buffer DMA mode Aug 18 23:15:28 volumio1 kernel: Periodic Transfer Interrupt Enhancement - disabled Aug 18 23:15:28 volumio1 kernel: Multiprocessor Interrupt Enhancement - disabled Aug 18 23:15:28 volumio1 kernel: OTG VER PARAM: 0, OTG VER FLAG: 0 Aug 18 23:15:28 volumio1 kernel: Dedicated Tx FIFOs mode Aug 18 23:15:28 volumio1 kernel: Aug 18 23:15:28 volumio1 kernel: WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = 99114000 dma = 0xd9114000 len=9024 Aug 18 23:15:28 volumio1 kernel: FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled Aug 18 23:15:28 volumio1 kernel: dwc_otg: Microframe scheduler enabled Aug 18 23:15:28 volumio1 kernel: Aug 18 23:15:28 volumio1 kernel: WARN::hcd_init_fiq:457: FIQ on core 1 Aug 18 23:15:28 volumio1 kernel: Aug 18 23:15:28 volumio1 kernel: WARN::hcd_init_fiq:458: FIQ ASM at 807cb80c length 36 Aug 18 23:15:28 volumio1 kernel: Aug 18 23:15:28 volumio1 kernel: WARN::hcd_init_fiq:497: MPHI regs_base at 9e810000 Aug 18 23:15:28 volumio1 kernel: dwc_otg 3f980000.usb: DWC OTG Controller Aug 18 23:15:28 volumio1 kernel: dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 Aug 18 23:15:28 volumio1 kernel: dwc_otg 3f980000.usb: irq 89, io mem 0x00000000 Aug 18 23:15:28 volumio1 kernel: Init: Port Power? op_state=1 Aug 18 23:15:28 volumio1 kernel: Init: Power Port (0) Aug 18 23:15:28 volumio1 kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01 Aug 18 23:15:28 volumio1 kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Aug 18 23:15:28 volumio1 kernel: usb usb1: Product: DWC OTG Controller Aug 18 23:15:28 volumio1 kernel: usb usb1: Manufacturer: Linux 6.1.69-v7+ dwc_otg_hcd Aug 18 23:15:28 volumio1 kernel: usb usb1: SerialNumber: 3f980000.usb Aug 18 23:15:28 volumio1 kernel: hub 1-0:1.0: USB hub found Aug 18 23:15:28 volumio1 kernel: hub 1-0:1.0: 1 port detected Aug 18 23:15:28 volumio1 kernel: dwc_otg: FIQ enabled Aug 18 23:15:28 volumio1 kernel: dwc_otg: NAK holdoff enabled Aug 18 23:15:28 volumio1 kernel: dwc_otg: FIQ split-transaction FSM enabled Aug 18 23:15:28 volumio1 kernel: Module dwc_common_port init Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver usb-storage Aug 18 23:15:28 volumio1 kernel: mousedev: PS/2 mouse device common for all mice Aug 18 23:15:28 volumio1 kernel: sdhci: Secure Digital Host Controller Interface driver Aug 18 23:15:28 volumio1 kernel: sdhci: Copyright(c) Pierre Ossman Aug 18 23:15:28 volumio1 kernel: sdhci-pltfm: SDHCI platform and OF driver helper Aug 18 23:15:28 volumio1 kernel: ledtrig-cpu: registered to indicate activity on CPUs Aug 18 23:15:28 volumio1 kernel: hid: raw HID events driver (C) Jiri Kosina Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver usbhid Aug 18 23:15:28 volumio1 kernel: usbhid: USB HID core driver Aug 18 23:15:28 volumio1 kernel: Initializing XFRM netlink socket Aug 18 23:15:28 volumio1 kernel: NET: Registered PF_PACKET protocol family Aug 18 23:15:28 volumio1 kernel: Key type dns_resolver registered Aug 18 23:15:28 volumio1 kernel: Registering SWP/SWPB emulation handler Aug 18 23:15:28 volumio1 kernel: registered taskstats version 1 Aug 18 23:15:28 volumio1 kernel: Loading compiled-in X.509 certificates Aug 18 23:15:28 volumio1 kernel: Key type .fscrypt registered Aug 18 23:15:28 volumio1 kernel: Key type fscrypt-provisioning registered Aug 18 23:15:28 volumio1 kernel: uart-pl011 3f201000.serial: cts_event_workaround enabled Aug 18 23:15:28 volumio1 kernel: 3f201000.serial: ttyAMA1 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 Aug 18 23:15:28 volumio1 kernel: serial serial0: tty port ttyAMA1 registered Aug 18 23:15:28 volumio1 kernel: bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer Aug 18 23:15:28 volumio1 kernel: bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver Aug 18 23:15:28 volumio1 kernel: mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0 Aug 18 23:15:28 volumio1 kernel: mmc-bcm2835 3f300000.mmcnr: DMA channel allocated Aug 18 23:15:28 volumio1 kernel: sdhost: log_buf @ add3ace7 (d9113000) Aug 18 23:15:28 volumio1 kernel: mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) Aug 18 23:15:28 volumio1 kernel: of_cfs_init Aug 18 23:15:28 volumio1 kernel: of_cfs_init: OK Aug 18 23:15:28 volumio1 kernel: Freeing unused kernel image (initmem) memory: 1024K Aug 18 23:15:28 volumio1 kernel: mmc0: host does not support reading read-only switch, assuming write-enable Aug 18 23:15:28 volumio1 kernel: mmc0: new high speed SDHC card at address 5048 Aug 18 23:15:28 volumio1 kernel: mmcblk0: mmc0:5048 SD16G 14.4 GiB Aug 18 23:15:28 volumio1 kernel: mmcblk0: p1 p2 p3 Aug 18 23:15:28 volumio1 kernel: mmcblk0: mmc0:5048 SD16G 14.4 GiB Aug 18 23:15:28 volumio1 kernel: mmc1: new high speed SDIO card at address 0001 Aug 18 23:15:28 volumio1 kernel: Run /init as init process Aug 18 23:15:28 volumio1 kernel: with arguments: Aug 18 23:15:28 volumio1 kernel: /init Aug 18 23:15:28 volumio1 kernel: splash Aug 18 23:15:28 volumio1 kernel: nodebug Aug 18 23:15:28 volumio1 kernel: with environment: Aug 18 23:15:28 volumio1 kernel: HOME=/ Aug 18 23:15:28 volumio1 kernel: TERM=linux Aug 18 23:15:28 volumio1 kernel: imgpart=UUID=0c3a77ec-ae84-4f1b-8028-c61cc251ffe5 Aug 18 23:15:28 volumio1 kernel: imgfile=/volumio_current.sqsh Aug 18 23:15:28 volumio1 kernel: bootpart=UUID=41CA-9A8B Aug 18 23:15:28 volumio1 kernel: datapart=UUID=0324d53a-d066-482b-b659-eb98af2b49e7 Aug 18 23:15:28 volumio1 kernel: uuidconfig=cmdline.txt Aug 18 23:15:28 volumio1 kernel: pcie_aspm=off Aug 18 23:15:28 volumio1 kernel: pci=pcie_bus_safe Aug 18 23:15:28 volumio1 kernel: bootdelay=7 Aug 18 23:15:28 volumio1 kernel: use_kmsg=no Aug 18 23:15:28 volumio1 kernel: fuse: init (API version 7.37) Aug 18 23:15:28 volumio1 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Aug 18 23:15:28 volumio1 kernel: usbcore: registered new interface driver uas Aug 18 23:15:28 volumio1 kernel: EXT4-fs (mmcblk0p2): recovery complete Aug 18 23:15:28 volumio1 kernel: EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. Aug 18 23:15:28 volumio1 kernel: loop0: detected capacity change from 0 to 983360 Aug 18 23:15:28 volumio1 kernel: EXT4-fs (mmcblk0p3): recovery complete Aug 18 23:15:28 volumio1 kernel: EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Quota mode: none. Aug 18 23:15:28 volumio1 systemd[1]: System time before build time, advancing clock. Aug 18 23:15:28 volumio1 kernel: NET: Registered PF_INET6 protocol family Aug 18 23:15:28 volumio1 kernel: Segment Routing with IPv6 Aug 18 23:15:28 volumio1 kernel: In-situ OAM (IOAM) with IPv6 Aug 18 23:15:28 volumio1 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) Aug 18 23:15:28 volumio1 systemd[1]: Detected architecture arm. Aug 18 23:15:28 volumio1 systemd[1]: Set hostname to . Aug 18 23:15:28 volumio1 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. Aug 18 23:15:28 volumio1 systemd[1]: Listening on udev Control Socket. Aug 18 23:15:28 volumio1 systemd[1]: Listening on fsck to fsckd communication Socket. Aug 18 23:15:28 volumio1 systemd[1]: Listening on RPCbind Server Activation Socket. Aug 18 23:15:28 volumio1 systemd[1]: Reached target System Time Synchronized. Aug 18 23:15:28 volumio1 systemd[1]: Created slice User and Session Slice. Aug 18 23:15:28 volumio1 systemd[1]: Reached target Slices. Aug 18 23:15:28 volumio1 systemd-journald[301]: Journal started Aug 18 23:15:28 volumio1 systemd-journald[301]: Runtime journal (/run/log/journal/d5012141e8efab18115b4334669e938a) is 7.5M, max 30.0M, 22.5M free. Aug 18 23:15:28 volumio1 kernel: i2c_dev: i2c /dev entries driver Aug 18 23:15:28 volumio1 fake-hwclock[304]: Mon Aug 19 02:15:28 UTC 2024 Aug 18 23:15:28 volumio1 systemd-modules-load[308]: Inserted module 'i2c_dev' Aug 18 23:15:28 volumio1 systemd[1]: Started Load Kernel Modules. Aug 18 23:15:28 volumio1 systemd[1]: Mounting Kernel Configuration File System... Aug 18 23:15:28 volumio1 systemd[1]: Mounting FUSE Control File System... Aug 18 23:15:28 volumio1 systemd[1]: Starting Apply Kernel Variables... Aug 18 23:15:28 volumio1 systemd[1]: Started Load/Save Random Seed. Aug 18 23:15:28 volumio1 systemd[1]: Mounted Kernel Configuration File System. Aug 18 23:15:28 volumio1 systemd[1]: Mounted FUSE Control File System. Aug 18 23:15:28 volumio1 volumio[300]: 512 MB or less RAM Detected, need to enable swap Aug 18 23:15:28 volumio1 systemd[1]: Started Apply Kernel Variables. Aug 18 23:15:28 volumio1 systemd[1]: Started Create System Users. Aug 18 23:15:28 volumio1 volumio[300]: Enabling Swap Aug 18 23:15:28 volumio1 kernel: ext4 filesystem being mounted at /swap supports timestamps until 2038 (0x7fffffff) Aug 18 23:15:28 volumio1 systemd[1]: Starting Create Static Device Nodes in /dev... Aug 18 23:15:28 volumio1 systemd[1]: Started udev Coldplug all Devices. Aug 18 23:15:28 volumio1 systemd[1]: Starting Helper to synchronize boot up for ifupdown... Aug 18 23:15:28 volumio1 volumio[300]: Setting swappiness to 40 Aug 18 23:15:28 volumio1 kernel: Adding 524228k swap on /swap/swapfile. Priority:-2 extents:14 across:11304956k SSFS Aug 18 23:15:28 volumio1 volumio[300]: vm.swappiness = 40 Aug 18 23:15:28 volumio1 systemd[1]: dynamicswap.service: Succeeded. Aug 18 23:15:28 volumio1 systemd[1]: Started Create Static Device Nodes in /dev. Aug 18 23:15:28 volumio1 systemd[1]: Starting udev Kernel Device Manager... Aug 18 23:15:28 volumio1 systemd[1]: Reached target Local File Systems (Pre). Aug 18 23:15:28 volumio1 systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Aug 18 23:15:28 volumio1 systemd[1]: Mounting /var/log... Aug 18 23:15:28 volumio1 systemd[1]: Mounting /var/spool/cups... Aug 18 23:15:28 volumio1 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Aug 18 23:15:28 volumio1 systemd[1]: Mounting /tmp... Aug 18 23:15:28 volumio1 systemd[1]: Mounted /var/log. Aug 18 23:15:28 volumio1 systemd[1]: Starting Flush Journal to Persistent Storage... Aug 18 23:15:28 volumio1 systemd[1]: Mounted /tmp. Aug 18 23:15:28 volumio1 systemd-udevd[333]: Network interface NamePolicy= disabled on kernel command line, ignoring. Aug 18 23:15:28 volumio1 systemd[1]: Mounted /var/spool/cups. Aug 18 23:15:28 volumio1 systemd[1]: Mounting /var/spool/cups/tmp... Aug 18 23:15:28 volumio1 systemd[1]: Started udev Kernel Device Manager. Aug 18 23:15:28 volumio1 systemd[1]: Mounted /var/spool/cups/tmp. Aug 18 23:15:28 volumio1 systemd[1]: Starting Show Plymouth Boot Screen... Aug 18 23:15:28 volumio1 systemd-journald[301]: Runtime journal (/run/log/journal/d5012141e8efab18115b4334669e938a) is 7.5M, max 30.0M, 22.5M free. Aug 18 23:15:28 volumio1 systemd[1]: Started Flush Journal to Persistent Storage. Aug 18 23:15:28 volumio1 systemd[1]: plymouth-start.service: Succeeded. Aug 18 23:15:28 volumio1 systemd[1]: Started Show Plymouth Boot Screen. Aug 18 23:15:28 volumio1 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Aug 18 23:15:28 volumio1 systemd[1]: Reached target Local Encrypted Volumes. Aug 18 23:15:28 volumio1 systemd[1]: Reached target Paths. Aug 18 23:15:28 volumio1 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Aug 18 23:15:29 volumio1 kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver Aug 18 23:15:29 volumio1 kernel: [vc_sm_connected_init]: start Aug 18 23:15:29 volumio1 kernel: mc: Linux media interface: v0.10 Aug 18 23:15:29 volumio1 kernel: [vc_sm_connected_init]: installed successfully Aug 18 23:15:29 volumio1 kernel: rpi-gpiomem 3f200000.gpiomem: window base 0x3f200000 size 0x00001000 Aug 18 23:15:29 volumio1 kernel: rpi-gpiomem 3f200000.gpiomem: initialised 1 regions as /dev/gpiomem Aug 18 23:15:29 volumio1 kernel: videodev: Linux video capture interface: v2.00 Aug 18 23:15:29 volumio1 kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 Aug 18 23:15:29 volumio1 kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp Aug 18 23:15:29 volumio1 kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31 Aug 18 23:15:29 volumio1 kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller Aug 18 23:15:29 volumio1 kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp Aug 18 23:15:29 volumio1 systemd[1]: Found device /dev/disk/by-uuid/41CA-9A8B. Aug 18 23:15:29 volumio1 kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. Aug 18 23:15:29 volumio1 kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored Aug 18 23:15:29 volumio1 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Aug 18 23:15:29 volumio1 kernel: bcm2835_audio bcm2835_audio: card created with 4 channels Aug 18 23:15:29 volumio1 kernel: Bluetooth: Core ver 2.22 Aug 18 23:15:29 volumio1 kernel: NET: Registered PF_BLUETOOTH protocol family Aug 18 23:15:29 volumio1 kernel: Bluetooth: HCI device and connection manager initialized Aug 18 23:15:29 volumio1 kernel: Bluetooth: HCI socket layer initialized Aug 18 23:15:29 volumio1 kernel: Bluetooth: L2CAP socket layer initialized Aug 18 23:15:29 volumio1 kernel: Bluetooth: SCO socket layer initialized Aug 18 23:15:30 volumio1 kernel: Bluetooth: HCI UART driver ver 2.3 Aug 18 23:15:30 volumio1 kernel: Bluetooth: HCI UART protocol H4 registered Aug 18 23:15:30 volumio1 kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered Aug 18 23:15:30 volumio1 kernel: Bluetooth: HCI UART protocol Broadcom registered Aug 18 23:15:30 volumio1 kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator Aug 18 23:15:30 volumio1 kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator Aug 18 23:15:30 volumio1 kernel: uart-pl011 3f201000.serial: no DMA platform data Aug 18 23:15:30 volumio1 systemd[1]: Starting File System Check on /dev/disk/by-uuid/41CA-9A8B... Aug 18 23:15:30 volumio1 kernel: Bluetooth: hci0: BCM: chip id 107 Aug 18 23:15:30 volumio1 kernel: Bluetooth: hci0: BCM: features 0x2f Aug 18 23:15:30 volumio1 kernel: Bluetooth: hci0: BCM4345C0 Aug 18 23:15:30 volumio1 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000 Aug 18 23:15:30 volumio1 kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch Aug 18 23:15:30 volumio1 kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Aug 18 23:15:30 volumio1 systemd-udevd[345]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 18 23:15:30 volumio1 kernel: cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf' Aug 18 23:15:30 volumio1 kernel: cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328' Aug 18 23:15:30 volumio1 kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Aug 18 23:15:30 volumio1 systemd-fsck[422]: fsck.fat 4.1 (2017-01-24) Aug 18 23:15:30 volumio1 systemd-fsck[422]: /dev/mmcblk0p1: 368 files, 134159/184582 clusters Aug 18 23:15:30 volumio1 systemd[1]: Started File System Check on /dev/disk/by-uuid/41CA-9A8B. Aug 18 23:15:31 volumio1 kernel: Bluetooth: hci0: BCM: features 0x2f Aug 18 23:15:31 volumio1 kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+ Aug 18 23:15:31 volumio1 kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342 Aug 18 23:15:31 volumio1 kernel: Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac) Aug 18 23:15:31 volumio1 kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Aug 18 23:15:31 volumio1 kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Aug 18 23:15:31 volumio1 kernel: usbcore: registered new interface driver brcmfmac Aug 18 23:15:31 volumio1 kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Aug 18 23:15:31 volumio1 systemd-udevd[349]: Using default interface naming scheme 'v240'. Aug 18 23:15:31 volumio1 systemd-udevd[349]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 18 23:15:31 volumio1 systemd-udevd[348]: Process '/usr/sbin/alsactl -E HOME=/run/alsa restore 1' failed with exit code 17. Aug 18 23:15:31 volumio1 systemd[1]: Created slice system-bthelper.slice. Aug 18 23:15:31 volumio1 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Starting Show Plymouth Boot Screen... Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Huge Pages File System being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Aug 18 23:15:32 volumio1 systemd[1]: Mounting /boot... Aug 18 23:15:32 volumio1 systemd[1]: Started File System Check Daemon to report status. Aug 18 23:15:32 volumio1 systemd[1]: Mounted /boot. Aug 18 23:15:32 volumio1 systemd[1]: plymouth-start.service: Succeeded. Aug 18 23:15:32 volumio1 systemd[1]: Started Show Plymouth Boot Screen. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Starting Load/Save RF Kill Switch Status... Aug 18 23:15:32 volumio1 systemd[1]: Reached target Local File Systems. Aug 18 23:15:32 volumio1 systemd[1]: Starting Preprocess NFS configuration... Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Aug 18 23:15:32 volumio1 systemd[1]: Starting Create Volatile Files and Directories... Aug 18 23:15:32 volumio1 systemd[1]: Started Helper to synchronize boot up for ifupdown. Aug 18 23:15:32 volumio1 systemd[1]: Found device /sys/subsystem/net/devices/wlan0. Aug 18 23:15:32 volumio1 systemd[1]: Started Load/Save RF Kill Switch Status. Aug 18 23:15:32 volumio1 systemd[1]: nfs-config.service: Succeeded. Aug 18 23:15:32 volumio1 systemd[1]: Started Preprocess NFS configuration. Aug 18 23:15:32 volumio1 systemd[1]: plymouth-read-write.service: Succeeded. Aug 18 23:15:32 volumio1 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Aug 18 23:15:32 volumio1 systemd[1]: Received SIGRTMIN+20 from PID 192 (plymouthd). Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Reached target NFS client services. Aug 18 23:15:32 volumio1 systemd[1]: Started ifup for wlan0. Aug 18 23:15:32 volumio1 systemd[1]: Starting Raise network interfaces... Aug 18 23:15:32 volumio1 systemd[1]: Started Create Volatile Files and Directories. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Aug 18 23:15:32 volumio1 systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Aug 18 23:15:32 volumio1 systemd[1]: Starting RPC bind portmap service... Aug 18 23:15:32 volumio1 systemd[1]: Started Update UTMP about System Boot/Shutdown. Aug 18 23:15:32 volumio1 systemd[1]: Reached target System Initialization. Aug 18 23:15:32 volumio1 systemd[1]: Started Daily Cleanup of Temporary Directories. Aug 18 23:15:32 volumio1 systemd[1]: Listening on D-Bus System Message Bus Socket. Aug 18 23:15:32 volumio1 systemd[1]: Started Daily apt download activities. Aug 18 23:15:32 volumio1 systemd[1]: Started Daily apt upgrade and clean activities. Aug 18 23:15:32 volumio1 systemd[1]: Reached target Timers. Aug 18 23:15:32 volumio1 systemd[1]: Listening on triggerhappy.socket. Aug 18 23:15:32 volumio1 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Aug 18 23:15:32 volumio1 systemd[1]: Reached target Sockets. Aug 18 23:15:32 volumio1 systemd[1]: Reached target Basic System. Aug 18 23:15:32 volumio1 systemd[1]: Started D-Bus System Message Bus. Aug 18 23:15:32 volumio1 systemd[1]: Starting WPA supplicant... Aug 18 23:15:32 volumio1 systemd[1]: Starting Wireless Services... Aug 18 23:15:32 volumio1 systemd[1]: Started MPD OLED Display. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Started volumio-remote-updater.service. Aug 18 23:15:32 volumio1 systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Aug 18 23:15:32 volumio1 systemd[1]: Starting dhcpcd on all interfaces... Aug 18 23:15:32 volumio1 systemd[1]: Starting triggerhappy global hotkey daemon... Aug 18 23:15:32 volumio1 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 18 23:15:32 volumio1 systemd[1]: Started UPnP Renderer front-end to MPD. Aug 18 23:15:32 volumio1 systemd[1]: Started Manage Sound Card State (restore and store). Aug 18 23:15:32 volumio1 systemd[1]: Started Volumio Iptables Module. Aug 18 23:15:32 volumio1 systemd[1]: Starting Save/Restore Sound Card State... Aug 18 23:15:32 volumio1 alsactl[584]: alsactl 1.1.8 daemon started Aug 18 23:15:32 volumio1 systemd[1]: Starting Login Service... Aug 18 23:15:32 volumio1 systemd[1]: Started Volumio Log Rotation Service. Aug 18 23:15:32 volumio1 systemd[1]: Starting Configure Bluetooth Modems connected by UART... Aug 18 23:15:32 volumio1 dhcpcd[576]: Not running dhcpcd because /etc/network/interfaces Aug 18 23:15:32 volumio1 dhcpcd[576]: defines some interfaces that will use a Aug 18 23:15:32 volumio1 dhcpcd[576]: DHCP client or static address Aug 18 23:15:32 volumio1 systemd[1]: Started RPC bind portmap service. Aug 18 23:15:32 volumio1 systemd[1]: dhcpcd.service: Control process exited, code=exited, status=6/NOTCONFIGURED Aug 18 23:15:32 volumio1 thd[577]: Unable to parse trigger line: Aug 18 23:15:32 volumio1 thd[577]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Aug 18 23:15:32 volumio1 thd[577]: Unable to parse trigger line: Aug 18 23:15:32 volumio1 thd[577]: Unable to parse trigger line: Aug 18 23:15:32 volumio1 thd[577]: Found socket passed from systemd Aug 18 23:15:32 volumio1 systemd[1]: dhcpcd.service: Failed with result 'exit-code'. Aug 18 23:15:32 volumio1 systemd[1]: Failed to start dhcpcd on all interfaces. Aug 18 23:15:32 volumio1 systemd[1]: Reached target Remote File Systems (Pre). Aug 18 23:15:32 volumio1 systemd[1]: Reached target Remote File Systems. Aug 18 23:15:33 volumio1 systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Aug 18 23:15:33 volumio1 systemd[1]: Reached target RPC Port Mapper. Aug 18 23:15:33 volumio1 systemd[1]: Started triggerhappy global hotkey daemon. Aug 18 23:15:33 volumio1 systemd-logind[589]: New seat seat0. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113). Aug 18 23:15:33 volumio1 avahi-daemon[575]: Successfully dropped root privileges. Aug 18 23:15:33 volumio1 avahi-daemon[575]: avahi-daemon 0.7 starting up. Aug 18 23:15:33 volumio1 systemd[1]: Started Login Service. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Successfully called chroot(). Aug 18 23:15:33 volumio1 avahi-daemon[575]: Successfully dropped remaining capabilities. Aug 18 23:15:33 volumio1 systemd[1]: Started Save/Restore Sound Card State. Aug 18 23:15:33 volumio1 systemd[1]: hciuart.service: Succeeded. Aug 18 23:15:33 volumio1 systemd[1]: Started Configure Bluetooth Modems connected by UART. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Loading service file /services/volumio.service. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Network interface enumeration completed. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Server startup complete. Host name is volumio1.local. Local service cookie is 358650135. Aug 18 23:15:33 volumio1 avahi-daemon[575]: Service "Volumio1" (/services/volumio.service) successfully established. Aug 18 23:15:33 volumio1 wpa_supplicant[567]: Successfully initialized wpa_supplicant Aug 18 23:15:34 volumio1 ifup[522]: ifup: waiting for lock on /run/network/ifstate.wlan0 Aug 18 23:15:34 volumio1 sh[521]: wlan0=wlan0 Aug 18 23:15:34 volumio1 systemd[1]: Started Avahi mDNS/DNS-SD Stack. Aug 18 23:15:34 volumio1 systemd[1]: Started WPA supplicant. Aug 18 23:15:34 volumio1 systemd[1]: Starting Raspberry Pi bluetooth helper... Aug 18 23:15:34 volumio1 systemd[1]: Reached target Sound Card. Aug 18 23:15:34 volumio1 systemd[1]: Started Raise network interfaces. Aug 18 23:15:34 volumio1 systemd[1]: Reached target Network. Aug 18 23:15:34 volumio1 bthelper[670]: Raspberry Pi BDADDR already set Aug 18 23:15:34 volumio1 volumio-remote-updater[573]: Error: No active session Aug 18 23:15:34 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:34] [info] asio async_connect error: system:111 (Connection refused) Aug 18 23:15:34 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:34] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 18 23:15:34 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:34] [error] handle_connect error: Underlying Transport Error Aug 18 23:15:34 volumio1 systemd[1]: Starting OpenBSD Secure Shell server... Aug 18 23:15:34 volumio1 systemd[1]: Starting Network Time Service... Aug 18 23:15:34 volumio1 volumio[578]: Could not open config: /tmp/upmpdcli.conf Aug 18 23:15:34 volumio1 systemd[1]: Starting Permit User Sessions... Aug 18 23:15:34 volumio1 systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Aug 18 23:15:34 volumio1 systemd[1]: Reached target Network is Online. Aug 18 23:15:34 volumio1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 18 23:15:34 volumio1 systemd[1]: Starting LSB: Brings up/down network automatically... Aug 18 23:15:34 volumio1 systemd[1]: Starting Samba NMB Daemon... Aug 18 23:15:34 volumio1 systemd[1]: Starting /etc/rc.local Compatibility... Aug 18 23:15:34 volumio1 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 18 23:15:34 volumio1 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 18 23:15:34 volumio1 systemd[1]: Started Raspberry Pi bluetooth helper. Aug 18 23:15:34 volumio1 systemd[1]: Started /etc/rc.local Compatibility. Aug 18 23:15:34 volumio1 loadcpufreq[604]: Loading cpufreq kernel modules...done (none). Aug 18 23:15:34 volumio1 systemd[1]: Started Permit User Sessions. Aug 18 23:15:34 volumio1 systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Aug 18 23:15:35 volumio1 systemd[1]: Starting LSB: set CPUFreq kernel parameters... Aug 18 23:15:35 volumio1 systemd[1]: Starting Hold until boot process finishes up... Aug 18 23:15:35 volumio1 systemd[1]: Starting Terminate Plymouth Boot Screen... Aug 18 23:15:35 volumio1 systemd[1]: Starting Bluetooth service... Aug 18 23:15:35 volumio1 systemd[1]: iptables.service: Succeeded. Aug 18 23:15:35 volumio1 systemd[1]: Received SIGRTMIN+21 from PID 192 (plymouthd). Aug 18 23:15:35 volumio1 systemd[1]: plymouth-quit-wait.service: Succeeded. Aug 18 23:15:35 volumio1 systemd[1]: Started Hold until boot process finishes up. Aug 18 23:15:35 volumio1 ntpd[728]: ntpd 4.2.8p12@1.3728-o (1): Starting Aug 18 23:15:35 volumio1 ntpd[728]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103 Aug 18 23:15:35 volumio1 systemd[1]: plymouth-quit.service: Succeeded. Aug 18 23:15:35 volumio1 systemd[1]: Started Terminate Plymouth Boot Screen. Aug 18 23:15:35 volumio1 ntpd[768]: proto: precision = 1.406 usec (-19) Aug 18 23:15:35 volumio1 systemd[1]: Started Network Time Service. Aug 18 23:15:35 volumio1 systemd[1]: Received SIGRTMIN+21 from PID 192 (n/a). Aug 18 23:15:35 volumio1 ifplugd[736]: Network Interface Plugging Daemon...skip eth0...done. Aug 18 23:15:35 volumio1 ntpd[768]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Aug 18 23:15:35 volumio1 systemd[1]: Started LSB: Brings up/down network automatically. Aug 18 23:15:35 volumio1 bluetoothd[760]: Bluetooth daemon 5.50 Aug 18 23:15:35 volumio1 ntpd[768]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Aug 18 23:15:35 volumio1 ntpd[768]: Listen and drop on 0 v6wildcard [::]:123 Aug 18 23:15:35 volumio1 ntpd[768]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Aug 18 23:15:35 volumio1 ntpd[768]: Listen normally on 2 lo 127.0.0.1:123 Aug 18 23:15:35 volumio1 ntpd[768]: Listening on routing socket on fd #19 for interface updates Aug 18 23:15:35 volumio1 ntpd[768]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 18 23:15:35 volumio1 ntpd[768]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 18 23:15:35 volumio1 bluetoothd[760]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Aug 18 23:15:35 volumio1 bluetoothd[760]: Starting SDP server Aug 18 23:15:35 volumio1 bluetoothd[760]: Excluding (cli) sap Aug 18 23:15:35 volumio1 systemd[1]: Started Getty on tty1. Aug 18 23:15:35 volumio1 systemd[1]: Reached target Login Prompts. Aug 18 23:15:35 volumio1 systemd[1]: Started Bluetooth service. Aug 18 23:15:35 volumio1 systemd[1]: Reached target Bluetooth. Aug 18 23:15:35 volumio1 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Aug 18 23:15:35 volumio1 kernel: Bluetooth: BNEP filters: protocol multicast Aug 18 23:15:35 volumio1 kernel: Bluetooth: BNEP socket layer initialized Aug 18 23:15:35 volumio1 cpufrequtils[750]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Aug 18 23:15:35 volumio1 systemd[1]: Started LSB: set CPUFreq kernel parameters. Aug 18 23:15:35 volumio1 bluetoothd[760]: Bluetooth management interface 1.22 initialized Aug 18 23:15:35 volumio1 dbus-daemon[551]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=760 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Aug 18 23:15:35 volumio1 kernel: Bluetooth: MGMT ver 1.22 Aug 18 23:15:35 volumio1 sshd[789]: Server listening on 0.0.0.0 port 22. Aug 18 23:15:35 volumio1 sshd[789]: Server listening on :: port 22. Aug 18 23:15:35 volumio1 bluetoothd[760]: Failed to set privacy: Rejected (0x0b) Aug 18 23:15:35 volumio1 systemd[1]: Started OpenBSD Secure Shell server. Aug 18 23:15:35 volumio1 systemd[1]: Starting Hostname Service... Aug 18 23:15:35 volumio1 haveged[532]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K Aug 18 23:15:35 volumio1 haveged[532]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488 Aug 18 23:15:35 volumio1 haveged[532]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99978 Aug 18 23:15:35 volumio1 haveged[532]: haveged: fills: 0, generated: 0 Aug 18 23:15:36 volumio1 dbus-daemon[551]: [system] Successfully activated service 'org.freedesktop.hostname1' Aug 18 23:15:36 volumio1 systemd[1]: Started Hostname Service. Aug 18 23:15:36 volumio1 nmbd[747]: [2024/08/18 23:15:36.298789, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Aug 18 23:15:36 volumio1 nmbd[747]: started asyncdns process 804 Aug 18 23:15:36 volumio1 nmbd[747]: [2024/08/18 23:15:36.301435, 0] ../lib/util/become_daemon.c:149(daemon_status) Aug 18 23:15:36 volumio1 nmbd[747]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Aug 18 23:15:36 volumio1 nmbd[747]: [2024/08/18 23:15:36.301633, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Aug 18 23:15:36 volumio1 nmbd[747]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Aug 18 23:15:36 volumio1 ntpd[768]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Aug 18 23:15:36 volumio1 wireless.js[569]: Cleaning previous... Aug 18 23:15:36 volumio1 sudo[828]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 18 23:15:36 volumio1 sudo[828]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:36 volumio1 sudo[828]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:36 volumio1 sudo[830]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 18 23:15:36 volumio1 sudo[830]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:37 volumio1 systemd[1]: systemd-rfkill.service: Succeeded. Aug 18 23:15:37 volumio1 ntpd[768]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Aug 18 23:15:37 volumio1 sudo[830]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:37 volumio1 wireless.js[569]: Stopped aP Aug 18 23:15:37 volumio1 sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 18 23:15:37 volumio1 sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:37 volumio1 sudo[845]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:37 volumio1 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 18 23:15:37 volumio1 sudo[847]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 18 23:15:37 volumio1 sudo[847]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:37 volumio1 sudo[847]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:37 volumio1 sudo[854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 18 23:15:37 volumio1 sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:37 volumio1 sudo[854]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:37 volumio1 sudo[856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 18 23:15:37 volumio1 sudo[856]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:38 volumio1 ntpd[768]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Aug 18 23:15:39 volumio1 ntpd[768]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Aug 18 23:15:39 volumio1 bthelper[670]: Changing power off succeeded Aug 18 23:15:39 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:39] [info] asio async_connect error: system:111 (Connection refused) Aug 18 23:15:39 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:39] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 18 23:15:39 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:39] [error] handle_connect error: Underlying Transport Error Aug 18 23:15:39 volumio1 bthelper[670]: [CHG] Controller B8:27:EB:21:88:9F Class: 0x0000041c Aug 18 23:15:39 volumio1 bthelper[670]: Changing power on succeeded Aug 18 23:15:40 volumio1 sudo[856]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:40 volumio1 wireless.js[569]: SETTING APPROPRIATE REG DOMAIN: MX Aug 18 23:15:40 volumio1 sudo[924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 18 23:15:40 volumio1 sudo[924]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:40 volumio1 sudo[924]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:40 volumio1 sudo[926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set MX Aug 18 23:15:40 volumio1 sudo[926]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:40 volumio1 sudo[926]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:40 volumio1 wireless.js[569]: SUCCESSFULLY SET NEW REGDOMAIN: MX Aug 18 23:15:40 volumio1 wireless.js[569]: Start wireless flow Aug 18 23:15:40 volumio1 wireless.js[569]: Stopped hotspot (if there).. Aug 18 23:15:40 volumio1 sudo[931]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 18 23:15:40 volumio1 sudo[931]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:40 volumio1 sudo[931]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:40 volumio1 sudo[933]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 18 23:15:40 volumio1 sudo[933]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:40 volumio1 sudo[933]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:40 volumio1 wireless.js[569]: DHCP IP Aug 18 23:15:40 volumio1 wireless.js[569]: Start ap Aug 18 23:15:40 volumio1 wpa_supplicant[943]: Successfully initialized wpa_supplicant Aug 18 23:15:40 volumio1 sudo[944]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Aug 18 23:15:40 volumio1 sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:40 volumio1 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 18 23:15:40 volumio1 dhcpcd[945]: dev: loaded udev Aug 18 23:15:40 volumio1 kernel: 8021q: 802.1Q VLAN Support v1.8 Aug 18 23:15:41 volumio1 dhcpcd-run-hooks[953]: wlan0: starting wpa_supplicant Aug 18 23:15:41 volumio1 dhcpcd-run-hooks[966]: wlan0: failed to start wpa_supplicant Aug 18 23:15:41 volumio1 dhcpcd-run-hooks[967]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Aug 18 23:15:41 volumio1 dhcpcd[945]: wlan0: connected to Access Point `' Aug 18 23:15:41 volumio1 dhcpcd[945]: no interfaces have a carrier Aug 18 23:15:41 volumio1 dhcpcd[945]: forked to background, child pid 981 Aug 18 23:15:41 volumio1 dhcpcd[981]: wlan0: waiting for carrier Aug 18 23:15:41 volumio1 sudo[944]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:41 volumio1 wireless.js[569]: trying... Aug 18 23:15:41 volumio1 sudo[992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:41 volumio1 sudo[992]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:41 volumio1 sudo[992]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:42 volumio1 wireless.js[569]: trying... Aug 18 23:15:42 volumio1 sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:42 volumio1 sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:42 volumio1 sudo[1018]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:43 volumio1 wpa_supplicant[957]: wlan0: Trying to associate with SSID 'TP-LINK_56460F' Aug 18 23:15:43 volumio1 wireless.js[569]: trying... Aug 18 23:15:43 volumio1 sudo[1045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:43 volumio1 sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:43 volumio1 sudo[1045]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:44 volumio1 wireless.js[569]: trying... Aug 18 23:15:44 volumio1 sudo[1065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:44 volumio1 sudo[1065]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:44 volumio1 sudo[1065]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:45 volumio1 wireless.js[569]: trying... Aug 18 23:15:45 volumio1 sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:45 volumio1 sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:45 volumio1 sudo[1091]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: carrier acquired Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: connected to Access Point `TP-LINK_56460F' Aug 18 23:15:46 volumio1 wpa_supplicant[957]: wlan0: Associated with 64:66:b3:56:46:0f Aug 18 23:15:46 volumio1 wpa_supplicant[957]: wlan0: CTRL-EVENT-CONNECTED - Connection to 64:66:b3:56:46:0f completed [id=0 id_str=] Aug 18 23:15:46 volumio1 wpa_supplicant[957]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 18 23:15:46 volumio1 dhcpcd[981]: DUID 00:01:00:01:2e:31:54:68:b8:27:eb:a0:c7:5f Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: IAID eb:de:77:60 Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: adding address fe80::ba27:ebff:fede:7760 Aug 18 23:15:46 volumio1 dhcpcd[981]: ipv6_addaddr1: Permission denied Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: carrier lost Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: carrier acquired Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: IAID eb:de:77:60 Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: rebinding lease of 192.168.1.185 Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: soliciting an IPv6 router Aug 18 23:15:46 volumio1 dhcpcd[981]: wlan0: probing address 192.168.1.185/24 Aug 18 23:15:46 volumio1 wireless.js[569]: trying... Aug 18 23:15:46 volumio1 sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:46 volumio1 sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:46 volumio1 sudo[1130]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:47 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:47] [info] asio async_connect error: system:111 (Connection refused) Aug 18 23:15:47 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:47] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Aug 18 23:15:47 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:47] [error] handle_connect error: Underlying Transport Error Aug 18 23:15:47 volumio1 wireless.js[569]: trying... Aug 18 23:15:47 volumio1 sudo[1150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:47 volumio1 sudo[1150]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:47 volumio1 sudo[1150]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:48 volumio1 wireless.js[569]: trying... Aug 18 23:15:48 volumio1 sudo[1176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:48 volumio1 sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:48 volumio1 sudo[1176]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:49 volumio1 wireless.js[569]: trying... Aug 18 23:15:49 volumio1 sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:49 volumio1 sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:49 volumio1 sudo[1203]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:50 volumio1 wireless.js[569]: trying... Aug 18 23:15:50 volumio1 sudo[1222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:50 volumio1 sudo[1222]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:50 volumio1 sudo[1222]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:51 volumio1 wireless.js[569]: trying... Aug 18 23:15:51 volumio1 sudo[1249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:51 volumio1 sudo[1249]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:51 volumio1 sudo[1249]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:52 volumio1 dhcpcd[981]: wlan0: leased 192.168.1.185 for 604800 seconds Aug 18 23:15:52 volumio1 avahi-daemon[575]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.185. Aug 18 23:15:52 volumio1 avahi-daemon[575]: New relevant interface wlan0.IPv4 for mDNS. Aug 18 23:15:52 volumio1 dhcpcd[981]: wlan0: adding route to 192.168.1.0/24 Aug 18 23:15:52 volumio1 avahi-daemon[575]: Registering new address record for 192.168.1.185 on wlan0.IPv4. Aug 18 23:15:52 volumio1 dhcpcd[981]: wlan0: adding default route via 192.168.1.1 Aug 18 23:15:52 volumio1 wireless.js[569]: trying... Aug 18 23:15:52 volumio1 sudo[1297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 18 23:15:52 volumio1 sudo[1297]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:52 volumio1 sudo[1297]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:52 volumio1 wireless.js[569]: Connected to: ----TP-LINK_56460F Aug 18 23:15:52 volumio1 wireless.js[569]: ---- Aug 18 23:15:52 volumio1 sudo[1300]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 18 23:15:52 volumio1 sudo[1300]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:52 volumio1 sudo[1300]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:52 volumio1 wireless.js[569]: ... joined AP, wlan0 IPv4 is 192.168.1.185, ipV6 is undefined Aug 18 23:15:52 volumio1 wireless.js[569]: It's done! AP Aug 18 23:15:53 volumio1 systemd[1]: Started Wireless Services. Aug 18 23:15:53 volumio1 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 18 23:15:53 volumio1 systemd[1]: Started Volumio Backend Module. Aug 18 23:15:53 volumio1 systemd[1]: Started Volumio Cpu Tweaker. Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: Setting RT Priority for mpd Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: pid 35's current scheduling policy: SCHED_OTHER Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: pid 35's current scheduling priority: 0 Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: Setting MPD Affinity Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: pid 3's current affinity mask: f Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Aug 18 23:15:53 volumio1 volumio-cpu-tweak[1306]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Aug 18 23:15:53 volumio1 systemd[1]: volumio_cpu_tweak.service: Succeeded. Aug 18 23:15:53 volumio1 ntpd[768]: Listen normally on 3 wlan0 192.168.1.185:123 Aug 18 23:15:53 volumio1 ntpd[768]: new interface(s) found: waking up resolver Aug 18 23:15:55 volumio1 volumio[1305]: info: ------------------------------------------- Aug 18 23:15:55 volumio1 volumio[1305]: info: ----- Volumio3 ---- Aug 18 23:15:55 volumio1 volumio[1305]: info: ------------------------------------------- Aug 18 23:15:55 volumio1 volumio[1305]: info: ----- System startup ---- Aug 18 23:15:55 volumio1 volumio[1305]: info: ------------------------------------------- Aug 18 23:15:56 volumio1 nmbd[747]: [2024/08/18 23:15:56.307510, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 18 23:15:56 volumio1 nmbd[747]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Aug 18 23:15:56 volumio1 systemd[1]: Started Samba NMB Daemon. Aug 18 23:15:56 volumio1 nmbd[747]: [2024/08/18 23:15:56.325255, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 18 23:15:56 volumio1 nmbd[747]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.185 for name WORKGROUP<1d>. Aug 18 23:15:56 volumio1 nmbd[747]: This response was from IP 192.168.1.12, reporting an IP address of 192.168.1.12. Aug 18 23:15:56 volumio1 systemd[1]: Starting Samba Winbind Daemon... Aug 18 23:15:56 volumio1 winbindd[1370]: [2024/08/18 23:15:56.704667, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Aug 18 23:15:56 volumio1 winbindd[1370]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 18 23:15:56 volumio1 winbindd[1370]: [2024/08/18 23:15:56.727760, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 18 23:15:56 volumio1 winbindd[1370]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Aug 18 23:15:56 volumio1 systemd[1]: Started Samba Winbind Daemon. Aug 18 23:15:56 volumio1 systemd[1]: Starting Samba SMB Daemon... Aug 18 23:15:57 volumio1 volumio[1305]: info: MYVOLUMIO Environment detected Aug 18 23:15:57 volumio1 volumio-remote-updater[573]: [2024-08-18 23:15:57] [connect] Successful connection Aug 18 23:15:57 volumio1 volumio[1305]: info: Plugin folders cleanup Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning into folder /volumio/app/plugins/ Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category audio_interface Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category miscellanea Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category music_service Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category plugins.json Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category system_controller Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category user_interface Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning into folder /data/plugins/ Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category music_service Aug 18 23:15:57 volumio1 volumio[1305]: info: Scanning category system_hardware Aug 18 23:15:57 volumio1 volumio[1305]: info: Plugin folders cleanup completed Aug 18 23:15:57 volumio1 volumio[1305]: info: ------------------------------------------- Aug 18 23:15:57 volumio1 volumio[1305]: info: ----- Core plugins startup ---- Aug 18 23:15:57 volumio1 volumio[1305]: info: ------------------------------------------- Aug 18 23:15:57 volumio1 volumio[1305]: info: Loading plugins from folder /volumio/app/plugins/ Aug 18 23:15:57 volumio1 volumio[1305]: info: Adding plugin upnp to MyMusic Plugins Aug 18 23:15:57 volumio1 volumio[1305]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 18 23:15:57 volumio1 volumio[1305]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 18 23:15:57 volumio1 systemd[1]: Started Samba SMB Daemon. Aug 18 23:15:57 volumio1 smbd[1375]: [2024/08/18 23:15:57.273379, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 18 23:15:57 volumio1 smbd[1375]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Aug 18 23:15:57 volumio1 systemd[1]: Reached target Multi-User System. Aug 18 23:15:57 volumio1 systemd[1]: Reached target Graphical Interface. Aug 18 23:15:57 volumio1 volumio[1305]: info: Loading plugins from folder /data/plugins/ Aug 18 23:15:57 volumio1 volumio[1305]: info: Loading plugin "system"... Aug 18 23:15:57 volumio1 systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 18 23:15:57 volumio1 volumio[1305]: info: Loading plugin "appearance"... Aug 18 23:15:57 volumio1 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 18 23:15:57 volumio1 systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 18 23:15:57 volumio1 systemd[1]: Startup finished in 17.635s (kernel) + 31.438s (userspace) = 49.074s. Aug 18 23:15:58 volumio1 volumio[1305]: info: Loading plugin "network"... Aug 18 23:15:58 volumio1 volumio[1305]: info: Refreshing Cached IP Addresses Aug 18 23:15:58 volumio1 sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 18 23:15:58 volumio1 sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:58 volumio1 sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 18 23:15:58 volumio1 sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:58 volumio1 volumio[1305]: info: Loading plugin "services"... Aug 18 23:15:58 volumio1 sudo[1392]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:58 volumio1 volumio[1305]: info: Loading plugin "alsa_controller"... Aug 18 23:15:58 volumio1 sudo[1390]: pam_unix(sudo:session): session closed for user root Aug 18 23:15:58 volumio1 sudo[1395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 18 23:15:58 volumio1 sudo[1395]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:58 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 18 23:15:58 volumio1 volumio[1305]: info: Loading plugin "wizard"... Aug 18 23:15:58 volumio1 volumio[1305]: info: Loading plugin "networkfs"... Aug 18 23:15:59 volumio1 volumio[1305]: info: Starting Udev Watcher for removable devices Aug 18 23:15:59 volumio1 sudo[1403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=oscar,password=242424,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.12/hd2\\Vol. 3. Beethoven - Symphonies nos. 4 & 6 \'Pastorale\' (NBC Symphony Orchestra) /mnt/NAS/Torrent Aug 18 23:15:59 volumio1 sudo[1403]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:59 volumio1 sudo[1405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=oscar,password=242424,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.12/hd2\\Torrents - Musica /mnt/NAS/Musica_-_Torrents Aug 18 23:15:59 volumio1 sudo[1405]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:15:59 volumio1 volumio[1305]: info: Ignoring mount for partition: boot Aug 18 23:15:59 volumio1 volumio[1305]: info: Ignoring mount for partition: volumio Aug 18 23:15:59 volumio1 volumio[1305]: info: Ignoring mount for partition: volumio_data Aug 18 23:15:59 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 18 23:15:59 volumio1 volumio[1305]: info: Loading plugin "volumio_command_line_client"... Aug 18 23:15:59 volumio1 volumio[1305]: info: Loading plugin "upnp"... Aug 18 23:15:59 volumio1 volumio[1305]: info: [1724033759106] Starting Upmpd Daemon Aug 18 23:15:59 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 18 23:15:59 volumio1 volumio[1305]: info: Loading plugin "my_music"... Aug 18 23:15:59 volumio1 volumio[1305]: info: Loading plugin "mpd"... Aug 18 23:15:59 volumio1 kernel: Key type cifs.spnego registered Aug 18 23:15:59 volumio1 kernel: Key type cifs.idmap registered Aug 18 23:15:59 volumio1 kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Aug 18 23:15:59 volumio1 kernel: CIFS: Attempting to mount \\192.168.1.12\hd2 Aug 18 23:15:59 volumio1 volumio[1305]: info: Loading plugin "upnp_browser"... Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "alarm-clock"... Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "airplay_emulation"... Aug 18 23:16:00 volumio1 volumio[1305]: info: Starting Shairport Sync Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "last_100"... Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "webradio"... Aug 18 23:16:00 volumio1 sudo[1405]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:00 volumio1 kernel: CIFS: Attempting to mount \\192.168.1.12\hd2 Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "i2s_dacs"... Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "volumiodiscovery"... Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** For more information see Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 18 23:16:00 volumio1 volumio[1305]: *** WARNING *** For more information see Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** For more information see Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 18 23:16:00 volumio1 node[1305]: *** WARNING *** For more information see Aug 18 23:16:00 volumio1 volumio[1305]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 18 23:16:00 volumio1 volumio[1305]: info: Discovery: Started advertising with name: Volumio1 Aug 18 23:16:00 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 18 23:16:00 volumio1 volumio[1305]: info: Loading plugin "spop"... Aug 18 23:16:00 volumio1 sudo[1403]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:02 volumio1 systemd[1]: systemd-fsckd.service: Succeeded. Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "outputs"... Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "albumart"... Aug 18 23:16:02 volumio1 volumio[1305]: info: Plugin example_plugin is not enabled Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "inputs"... Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "updater_comm"... Aug 18 23:16:02 volumio1 volumio[1305]: info: Plugin mpdemulation is not enabled Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "rest_api"... Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "websocket"... Aug 18 23:16:02 volumio1 sudo[1395]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:02 volumio1 volumio[1305]: info: Starting Socket.io Server version 2.3.0 Aug 18 23:16:02 volumio1 volumio[1305]: info: Loading plugin "rotaryencoder2"... Aug 18 23:16:02 volumio1 volumio[1305]: Forking 3 albumart workers Aug 18 23:16:03 volumio1 volumio[1305]: info: Loading i18n strings for locale es Aug 18 23:16:03 volumio1 volumio[1305]: Updating browse sources language Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:03 volumio1 volumio[1305]: Starting albumart workers Aug 18 23:16:03 volumio1 volumio[1305]: Starting albumart workers Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::initPlayerControls Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 18 23:16:03 volumio1 volumio[1305]: Express server listening on port 3000 Aug 18 23:16:03 volumio1 volumio[1305]: [Metrics] WebUI: 8s 835.69ms Aug 18 23:16:03 volumio1 volumio[1305]: Starting albumart workers Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreStateMachine::resetVolumioState Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreStateMachine::getcurrentVolume Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::volumioRetrievevolume Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreStateMachine::pushState Aug 18 23:16:03 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::volumioPushState Aug 18 23:16:03 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:03 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:04 volumio1 volumio[1305]: info: Reloading queue from file Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreStateMachine::setRepeat null single undefined Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreStateMachine::pushState Aug 18 23:16:04 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::volumioPushState Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreStateMachine::setRandom null Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreStateMachine::pushState Aug 18 23:16:04 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::volumioPushState Aug 18 23:16:04 volumio1 volumio[1305]: info: Setting Device type: Raspberry PI Aug 18 23:16:04 volumio1 volumio[1305]: info: Completed loading Core Plugins Aug 18 23:16:04 volumio1 volumio[1305]: info: Preparing to generate the ALSA configuration file Aug 18 23:16:04 volumio1 volumio[1305]: info: Asound.conf file unchanged, so no further update is needed Aug 18 23:16:04 volumio1 volumio[1305]: info: Output device has changed, restarting MPD Aug 18 23:16:04 volumio1 volumio[1305]: info: Output device has changed, restarting Shairport Sync Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 sudo[1483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 18 23:16:04 volumio1 sudo[1485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 18 23:16:04 volumio1 sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 sudo[1485]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 sudo[1483]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:04 volumio1 volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 18 23:16:04 volumio1 volumio[1305]: info: ___________ START PLUGINS ___________ Aug 18 23:16:04 volumio1 volumio[1305]: info: ControllerMpd::onStart: Initializing MPD Aug 18 23:16:04 volumio1 volumio[1305]: info: Creating MPD Configuration file Aug 18 23:16:04 volumio1 systemd[1]: Listening on mpd.socket. Aug 18 23:16:04 volumio1 systemd[1]: Starting Music Player Daemon... Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 18 23:16:04 volumio1 volumio[1305]: info: [1724033764530] CoreMusicLibrary::Adding element Media Servers Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:04 volumio1 sudo[1510]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 18 23:16:04 volumio1 sudo[1510]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 sudo[1510]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:04 volumio1 sudo[1512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 18 23:16:04 volumio1 sudo[1512]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 sudo[1505]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 18 23:16:04 volumio1 sudo[1505]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 sudo[1505]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:04 volumio1 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 18 23:16:04 volumio1 systemd[1]: mpd.service: Succeeded. Aug 18 23:16:04 volumio1 systemd[1]: Stopped Music Player Daemon. Aug 18 23:16:04 volumio1 volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 systemd[1]: Starting Music Player Daemon... Aug 18 23:16:04 volumio1 volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 18 23:16:04 volumio1 volumio[1305]: info: [1724033764741] CoreMusicLibrary::Adding element Last_100 Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 18 23:16:04 volumio1 volumio[1305]: info: [1724033764744] CoreMusicLibrary::Adding element Webradio Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 18 23:16:04 volumio1 volumio[1305]: info: Initializing BBC Radios Aug 18 23:16:04 volumio1 volumio[1305]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:04 volumio1 sudo[1527]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 18 23:16:04 volumio1 sudo[1527]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:04 volumio1 sudo[1527]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 18 23:16:04 volumio1 sudo[1527]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:04 volumio1 volumio[1305]: info: Creating Spotify config file Aug 18 23:16:04 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:04 volumio1 volumio[1305]: info: Volumio Calling Home Aug 18 23:16:05 volumio1 volumio[1305]: info: Discovery: adding a9988878-90f7-4ed2-8b05-9f31932d484c Aug 18 23:16:05 volumio1 volumio[1305]: info: Discovery: Found device Volumio1 Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:05 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:05 volumio1 sudo[1546]: 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 Aug 18 23:16:05 volumio1 sudo[1546]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 volumio[1305]: info: MPD Permissions set Aug 18 23:16:05 volumio1 volumio[1305]: info: MPD Permissions set Aug 18 23:16:05 volumio1 volumio[1305]: info: Spotify config file written Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:05 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:05 volumio1 sudo[1550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 18 23:16:05 volumio1 sudo[1550]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 volumio[1305]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 18 23:16:05 volumio1 volumio[1305]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 systemd[1]: Started go-librespot Daemon. Aug 18 23:16:05 volumio1 go-librespot[1566]: Librespot-go daemon starting... Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 18 23:16:05 volumio1 sudo[1550]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:05 volumio1 kernel: rotary-encoder rotary@17: gray Aug 18 23:16:05 volumio1 kernel: input: rotary@17 as /devices/platform/rotary@17/input/input0 Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 18 23:16:05 volumio1 sudo[1546]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:05 volumio1 volumio[1305]: info: Starting Shairport Sync Aug 18 23:16:05 volumio1 volumio[1305]: info: Starting Shairport Sync Aug 18 23:16:05 volumio1 volumio[1305]: info: Starting Shairport Sync Aug 18 23:16:05 volumio1 sudo[1589]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 18 23:16:05 volumio1 sudo[1589]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 systemd-udevd[1568]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Aug 18 23:16:05 volumio1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:05 volumio1 sudo[1592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 18 23:16:05 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:05 volumio1 sudo[1592]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 sudo[1595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 18 23:16:05 volumio1 sudo[1595]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:05 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:05 volumio1 systemd[1]: shairport-sync.service: Succeeded. Aug 18 23:16:05 volumio1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 18 23:16:05 volumio1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 18 23:16:05 volumio1 sudo[1589]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:05 volumio1 sudo[1595]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:05 volumio1 sudo[1592]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:05 volumio1 volumio[1305]: info: Shairport-Sync Started Aug 18 23:16:05 volumio1 volumio[1305]: Error adding Membership: Error: addMembership EINVAL Aug 18 23:16:05 volumio1 volumio[1305]: info: Shairport-Sync Started Aug 18 23:16:05 volumio1 volumio[1305]: info: Shairport-Sync Started Aug 18 23:16:05 volumio1 sudo[1603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 18 23:16:05 volumio1 sudo[1605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 18 23:16:05 volumio1 sudo[1603]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:05 volumio1 sudo[1605]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:06 volumio1 sudo[1605]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:06 volumio1 sudo[1603]: pam_unix(sudo:session): session closed for user root Aug 18 23:16:06 volumio1 systemd[1]: systemd-hostnamed.service: Succeeded. Aug 18 23:16:06 volumio1 volumio[1305]: verbose: New Socket.io Connection to 192.168.1.185 from 192.168.1.17 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko/20100101 Firefox/129.0 Engine version: 3 Transport: polling Total Clients: 3 Aug 18 23:16:06 volumio1 go-librespot[1566]: time="2024-08-18T23:16:06-03:00" level=info msg="generated new device id: d62d7154771ffff2cb5d02484f701900ae65e8b7" Aug 18 23:16:06 volumio1 go-librespot[1566]: time="2024-08-18T23:16:06-03:00" level=debug msg="stored credentials found for jzamorano-ar" Aug 18 23:16:06 volumio1 volumio[1305]: info: Volumio called home Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetVisibleSources Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetState Aug 18 23:16:06 volumio1 volumio[1305]: info: CorePlayQueue::getTrack 0 Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::volumioGetQueue Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreStateMachine::getQueue Aug 18 23:16:06 volumio1 volumio[1305]: info: CorePlayQueue::getQueue Aug 18 23:16:06 volumio1 volumio[1305]: info: Listing playlists Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 18 23:16:06 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 18 23:16:06 volumio1 volumio[1305]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 18 23:16:06 volumio1 volumio[1305]: SPOTIFY: BQAZ9-YdgmRYLupOzt-77WBuC4bTn7jsv5L7OF06mKXSkTutYj2EWQX5hCbm0OQ1I3m9irzNiWwz000-UJJBeUdSaD_kCtR1sJDEpSjuGfNY3vWN8gWrkjkTbJX87ibhz_-6D6Qulio_UnoQdw5YvwX709yvwuzyWY9BdOTbJhv1wSdYJttGdM3Lxs3yYA0s_BixBQpQjVFOF8OvCsIxzNnMCqCpw40Ne0lFpDNc7t91Ckp5Mm7R42q2Y6pixA Aug 18 23:16:06 volumio1 volumio[1305]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 18 23:16:06 volumio1 volumio[1305]: info: New Spotify access token = BQAZ9-YdgmRYLupOzt-77WBuC4bTn7jsv5L7OF06mKXSkTutYj2EWQX5hCbm0OQ1I3m9irzNiWwz000-UJJBeUdSaD_kCtR1sJDEpSjuGfNY3vWN8gWrkjkTbJX87ibhz_-6D6Qulio_UnoQdw5YvwX709yvwuzyWY9BdOTbJhv1wSdYJttGdM3Lxs3yYA0s_BixBQpQjVFOF8OvCsIxzNnMCqCpw40Ne0lFpDNc7t91Ckp5Mm7R42q2Y6pixA Aug 18 23:16:06 volumio1 volumio[1305]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 18 23:16:07 volumio1 go-librespot[1566]: time="2024-08-18T23:16:07-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 18 23:16:07 volumio1 go-librespot[1566]: time="2024-08-18T23:16:07-03:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 18 23:16:07 volumio1 go-librespot[1566]: time="2024-08-18T23:16:07-03:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 18 23:16:07 volumio1 go-librespot[1566]: time="2024-08-18T23:16:07-03:00" level=debug msg="zeroconf server listening on port 43817" Aug 18 23:16:07 volumio1 volumio[1305]: Searching all installed plugins Aug 18 23:16:07 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 18 23:16:07 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: , search Aug 18 23:16:07 volumio1 volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 18 23:16:07 volumio1 volumio[1305]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 18 23:16:07 volumio1 volumio[1305]: TypeError: Cannot read property 'then' of undefined Aug 18 23:16:07 volumio1 volumio[1305]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1582:17) Aug 18 23:16:07 volumio1 volumio[1305]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Aug 18 23:16:07 volumio1 volumio[1305]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Aug 18 23:16:07 volumio1 volumio[1305]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Aug 18 23:16:07 volumio1 volumio[1305]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:485:44) Aug 18 23:16:07 volumio1 volumio[1305]: at Socket.emit (events.js:315:20) Aug 18 23:16:07 volumio1 volumio[1305]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 18 23:16:07 volumio1 volumio[1305]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 18 23:16:07 volumio1 volumio[1305]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 18 23:16:07 volumio1 go-librespot[1566]: time="2024-08-18T23:16:07-03:00" level=debug msg="obtained new client token: AADyrdudmfquXmYS6G+90MEWrZNoHHs+5GIrgDGBp1McozTxl+xQ5GjNAX2ngBQZWEUTcI3YgZaXprzzgb6QrOppbb8tr+72VXYG/cqceLHZOwpeOnTQqKF+GEnn+8CvZnNff7q8Pua1t5O2POWQ49HEXzIBCVrrBGIq5UW89x4KFjyDsK61fUBGimYJRFTMr82KXqOLOKm82R6iHXCkXbvnxY3MLhaZ1cgWG6YmWWYmv+IQv3B1nwUo2A==" Aug 18 23:16:08 volumio1 go-librespot[1566]: time="2024-08-18T23:16:08-03:00" level=debug msg="completed keyexchange" Aug 18 23:16:08 volumio1 sudo[1632]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-18 23:15 Aug 18 23:16:08 volumio1 sudo[1632]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 18 23:16:08 volumio1 go-librespot[1566]: time="2024-08-18T23:16:08-03:00" level=debug msg="completed challenge" 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"