-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Mon 2025-09-01 13:18:54 CEST. -- Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver hub Sep 01 13:18:31 ict kernel: usbcore: registered new device driver usb Sep 01 13:18:31 ict kernel: media: Linux media interface: v0.10 Sep 01 13:18:31 ict kernel: Linux video capture interface: v2.00 Sep 01 13:18:31 ict kernel: pps_core: LinuxPPS API ver. 1 registered Sep 01 13:18:31 ict kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti Sep 01 13:18:31 ict kernel: PTP clock support registered Sep 01 13:18:31 ict kernel: dmi: Firmware registration failed. Sep 01 13:18:31 ict kernel: secmon: reserve_mem_size:0x300000 Sep 01 13:18:31 ict kernel: secmon secmon: assigned reserved memory node linux,secmon Sep 01 13:18:31 ict kernel: secmon: get page:ffffffbf00140000, 5000 Sep 01 13:18:31 ict kernel: secmon: share in base: 0xffffffc0050fe000, share out base: 0xffffffc0050ff000 Sep 01 13:18:31 ict kernel: secmon: phy_in_base: 0x50fe000, phy_out_base: 0x50ff000 Sep 01 13:18:31 ict kernel: hdmitx: system: amhdmitx_probe start Sep 01 13:18:31 ict kernel: hdmitx: system: Ver: 20190815 Sep 01 13:18:31 ict kernel: hdmitx: system: hdmitx_device.chip_type : 12 Sep 01 13:18:31 ict kernel: hdmitx: system: not find match pwr-ctl Sep 01 13:18:31 ict kernel: hdmitx: system: not find drm_amhdmitx Sep 01 13:18:31 ict kernel: hdmitx: system: hpd irq = 37 Sep 01 13:18:31 ict kernel: hdmitx: system: hdcp22_tx_skp failed to probe Sep 01 13:18:31 ict kernel: hdmitx: system: hdcp22_tx_esm failed to probe Sep 01 13:18:31 ict kernel: vout: vout1: register server: hdmitx_vout_server Sep 01 13:18:31 ict kernel: vout: vout2: register server: hdmitx_vout2_server Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xffd00000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff634400 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff900000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff800000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff63c000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xffd00000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff608000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xff600000 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx20: Mapped PHY: 0xffe01000 Sep 01 13:18:31 ict kernel: hdmitx: hw: alread display in uboot 0x10 Sep 01 13:18:31 ict kernel: hdmitx: hw: avmute set to 1 Sep 01 13:18:31 ict kernel: hdmitx: system: fmt_attr 444,8bit Sep 01 13:18:31 ict kernel: hdmitx: system: fmt_attr 444,8bit Sep 01 13:18:31 ict kernel: hdmitx: system: amhdmitx_probe end Sep 01 13:18:31 ict kernel: vout: create vout attribute OK Sep 01 13:18:31 ict kernel: vout: vout_fops_create OK Sep 01 13:18:31 ict kernel: vout: vout1: register server: nulldisp_vout_server Sep 01 13:18:31 ict kernel: vout: tvout monitor interval:500(ms), timeout cnt:20 Sep 01 13:18:31 ict kernel: hdmitx: hdmitx_set_current_vmode[3877] Sep 01 13:18:31 ict kernel: hdmitx: system: recalc before 1080p60hz 60 1 Sep 01 13:18:31 ict kernel: hdmitx: system: recalc after 1080p60hz 2997 50 Sep 01 13:18:31 ict kernel: hdmitx: alread display in uboot Sep 01 13:18:31 ict kernel: vout: init mode 1080p60hz set ok Sep 01 13:18:31 ict kernel: vout: aml_tvout_mode_monitor Sep 01 13:18:31 ict kernel: vout: aml_vout_probe OK Sep 01 13:18:31 ict kernel: chip type:0x2b Sep 01 13:18:31 ict kernel: MEMORY:[0+ed800000] Sep 01 13:18:31 ict kernel: ramdump_probe, storage device:data Sep 01 13:18:31 ict kernel: NO valid ramdump args:0 0 Sep 01 13:18:31 ict kernel: ramdump_probe, set sticky to 8ed8 Sep 01 13:18:31 ict kernel: Advanced Linux Sound Architecture Driver Initialized. Sep 01 13:18:31 ict kernel: NetLabel: Initializing Sep 01 13:18:31 ict kernel: NetLabel: domain hash size = 128 Sep 01 13:18:31 ict kernel: NetLabel: protocols = UNLABELED CIPSOv4 Sep 01 13:18:31 ict kernel: NetLabel: unlabeled traffic allowed by default Sep 01 13:18:31 ict kernel: clocksource: Switched to clocksource arch_sys_counter Sep 01 13:18:31 ict kernel: VFS: Disk quotas dquot_6.6.0 Sep 01 13:18:31 ict kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Sep 01 13:18:31 ict kernel: NET: Registered protocol family 2 Sep 01 13:18:31 ict kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes) Sep 01 13:18:31 ict kernel: TCP bind hash table entries: 32768 (order: 7, 524288 bytes) Sep 01 13:18:31 ict kernel: TCP: Hash tables configured (established 32768 bind 32768) Sep 01 13:18:31 ict kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes) Sep 01 13:18:31 ict kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes) Sep 01 13:18:31 ict kernel: NET: Registered protocol family 1 Sep 01 13:18:31 ict kernel: PCI: CLS 0 bytes, default 64 Sep 01 13:18:31 ict kernel: Unpacking initramfs... Sep 01 13:18:31 ict kernel: Freeing initrd memory: 12956K Sep 01 13:18:31 ict kernel: hw perfevents: clusterb_enabled = 0 Sep 01 13:18:31 ict kernel: hw perfevents: cpumasks 0xf, 0x0 Sep 01 13:18:31 ict kernel: hw perfevents: cluster A irq = 18 Sep 01 13:18:31 ict kernel: hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available Sep 01 13:18:31 ict kernel: audit: initializing netlink subsys (disabled) Sep 01 13:18:31 ict kernel: audit: type=2000 audit(0.980:1): initialized Sep 01 13:18:31 ict kernel: workingset: timestamp_bits=46 max_order=20 bucket_order=0 Sep 01 13:18:31 ict kernel: Registering sdcardfs 0.1 Sep 01 13:18:31 ict kernel: SELinux: Registering netfilter hooks Sep 01 13:18:31 ict kernel: NET: Registered protocol family 38 Sep 01 13:18:31 ict kernel: Key type asymmetric registered Sep 01 13:18:31 ict kernel: Asymmetric key parser 'x509' registered Sep 01 13:18:31 ict kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 243) Sep 01 13:18:31 ict kernel: io scheduler noop registered (default) Sep 01 13:18:31 ict kernel: io scheduler deadline registered Sep 01 13:18:31 ict kernel: io scheduler cfq registered Sep 01 13:18:31 ict kernel: meson-pwm ff802000.pwm: pwm pinmux : can't get pinctrl Sep 01 13:18:31 ict kernel: random: fast init done Sep 01 13:18:31 ict kernel: random: crng init done Sep 01 13:18:31 ict kernel: gpiomem-aml ff634000.gpiomem: Initialised: GPIO register area is 2 Sep 01 13:18:31 ict kernel: gpiomem-aml ff634000.gpiomem: Initialised: Registers at start:0xff634000 end:0xff634fff size:0x00000fff Sep 01 13:18:31 ict kernel: gpiomem-aml ff634000.gpiomem: Initialised: Registers at start:0xff800000 end:0xff800fff size:0x00000fff Sep 01 13:18:31 ict kernel: [drm] Initialized Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: Continuing without Mali regulator control Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: max pp is 2 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: set min pp to default 1 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: min pp is 1 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: min clk is 4 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: hiu io source 0xffffff80084d9000 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: hiu io source 0xffffff80084db000 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: num of pp used most of time 1 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: clock dvfs cfg table size is 6 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: max clk set 4 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: max clk is 4 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: turbo clk set to 5 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: turbo clk is 5 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: default clk set to 4 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: default clk is 4 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================0==================== clk_freq= 285714285, clk_parent=fclk_div7, voltage=1150, keep_count=5, threshod=<100 190>, clk_sample=285 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================1==================== clk_freq= 400000000, clk_parent=fclk_div5, voltage=1150, keep_count=5, threshod=<152 207>, clk_sample=400 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================2==================== clk_freq= 500000000, clk_parent=fclk_div4, voltage=1150, keep_count=5, threshod=<180 220>, clk_sample=500 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================3==================== clk_freq= 666666666, clk_parent=fclk_div3, voltage=1150, keep_count=5, threshod=<210 236>, clk_sample=666 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================4==================== clk_freq= 846000000, clk_parent= gp0_pll, voltage=1150, keep_count=5, threshod=<230 255>, clk_sample=846 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: ====================5==================== clk_freq= 846000000, clk_parent= gp0_pll, voltage=1150, keep_count=5, threshod=<230 255>, clk_sample=846 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: clock dvfs table size is 6 Sep 01 13:18:31 ict kernel: mali_plat=ffffff800a6b8250 Sep 01 13:18:31 ict kernel: meson_gcooldev is null, no set min status Sep 01 13:18:31 ict kernel: gpu cooling register okay with err=0 Sep 01 13:18:31 ict kernel: meson_gcooldev is null, no set min status Sep 01 13:18:31 ict kernel: gpu core cooling register okay with err=0 Sep 01 13:18:31 ict kernel: shader_present=1, tiler_present=1, l2_present=1 Sep 01 13:18:31 ict kernel: Mali_pwr_on:gpu_irq : 200 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: GPU identified as 0x3 arch 7.0.9 r0p0 status 0 Sep 01 13:18:31 ict kernel: mali ffe40000.bifrost: Probed as mali0 Sep 01 13:18:31 ict kernel: Unable to detect cache hierarchy for CPU 0 Sep 01 13:18:31 ict kernel: loop: module loaded Sep 01 13:18:31 ict kernel: mtdoops: mtd device (mtddev=name/number) must be supplied Sep 01 13:18:31 ict kernel: libphy: Fixed MDIO Bus: probed Sep 01 13:18:31 ict kernel: REG0:Addr = ffffff80084f1540 Sep 01 13:18:31 ict kernel: ee eth reset:Addr = ffffff80084f3008 Sep 01 13:18:31 ict kernel: read auto_cali_idx fail Sep 01 13:18:31 ict kernel: Not set cali_val for REG1 Sep 01 13:18:31 ict kernel: meson6-dwmac ff3f0000.ethernet: no reset control found Sep 01 13:18:31 ict kernel: stmmac - user ID: 0x11, Synopsys ID: 0x37 Sep 01 13:18:31 ict kernel: Ring mode enabled Sep 01 13:18:31 ict kernel: DMA HW capability register supported Sep 01 13:18:31 ict kernel: Normal descriptors Sep 01 13:18:31 ict kernel: RX Checksum Offload Engine supported Sep 01 13:18:31 ict kernel: COE Type 2 Sep 01 13:18:31 ict kernel: TX Checksum insertion supported Sep 01 13:18:31 ict kernel: Wake-Up On Lan supported Sep 01 13:18:31 ict kernel: eth%d: device MAC address 00:1e:06:4a:58:79 Sep 01 13:18:31 ict kernel: Enable RX Mitigation via HW Watchdog Timer Sep 01 13:18:31 ict kernel: libphy: stmmac: probed Sep 01 13:18:31 ict kernel: eth%d: PHY ID 001cc916 at 0 IRQ POLL (stmmac-0:00) active Sep 01 13:18:31 ict kernel: eth%d: PHY ID 001cc916 at 7 IRQ POLL (stmmac-0:07) Sep 01 13:18:31 ict kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver Sep 01 13:18:31 ict kernel: ehci-pci: EHCI PCI platform driver Sep 01 13:18:31 ict kernel: ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver cdc_acm Sep 01 13:18:31 ict kernel: cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver usb-storage Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver usbserial Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver usbserial_generic Sep 01 13:18:31 ict kernel: usbserial: USB Serial support registered for generic Sep 01 13:18:31 ict kernel: mousedev: PS/2 mouse device common for all mice Sep 01 13:18:31 ict kernel: i2c /dev entries driver Sep 01 13:18:31 ict kernel: lirc_helper: wakeupkey 0xffffffff, protocol 0x1 Sep 01 13:18:31 ict kernel: ledtrig-cpu: registered to indicate activity on CPUs Sep 01 13:18:31 ict kernel: hidraw: raw HID events driver (C) Jiri Kosina Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver usbhid Sep 01 13:18:31 ict kernel: usbhid: USB HID core driver Sep 01 13:18:31 ict kernel: value of voltage_tolerance 0 Sep 01 13:18:31 ict kernel: meson_cpufreq_init:don't find the node Sep 01 13:18:31 ict kernel: value of gp1_clk_target 0 Sep 01 13:18:31 ict kernel: dvfs [meson_cpufreq_init] - cluster 0 freq 2016000 Sep 01 13:18:31 ict kernel: dvfs [meson_cpufreq_init] - cluster 0 freq 2100000 Sep 01 13:18:31 ict kernel: cpu cpu0: meson_cpufreq_init: CPU 0 initialized Sep 01 13:18:31 ict kernel: ff803000.serial: clock gate not found Sep 01 13:18:31 ict kernel: meson_uart ff803000.serial: ==uart0 reg addr = ffffff80084f9000 Sep 01 13:18:31 ict kernel: ff803000.serial: ttyS0 at MMIO 0xff803000 (irq = 26, base_baud = 1500000) is a meson_uart Sep 01 13:18:31 ict kernel: meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 0 to 115200 Sep 01 13:18:31 ict kernel: console [ttyS0] enabled Sep 01 13:18:31 ict kernel: amlogic-new-usb2-v2 ffe09000.usb2phy: USB2 phy probe:phy_mem:0xffe09000, iomap phy_base:0xffffff80084fb000 Sep 01 13:18:31 ict kernel: amlogic-new-usb3-v2 ffe09080.usb3phy: USB3 phy probe:phy_mem:0xffe09080, iomap phy_base:0xffffff8008629080 Sep 01 13:18:31 ict kernel: aml_dma ff63e000.aml_dma: Aml dma Sep 01 13:18:31 ict kernel: aml_aes_dma ff63e000.aml_dma:aml_aes: Aml AES_dma Sep 01 13:18:31 ict kernel: aml_sha_dma ff63e000.aml_dma:aml_sha: Aml SHA1/SHA224/SHA256 dma Sep 01 13:18:31 ict kernel: gpio-keypad: probe of ff800000.gpio_keypad failed with error -22 Sep 01 13:18:31 ict kernel: efusekeynum: 1 Sep 01 13:18:31 ict kernel: efusekeyname: uuid offset: 0 size: 32 Sep 01 13:18:31 ict kernel: efuse efuse: probe OK! Sep 01 13:18:31 ict kernel: ion_dev soc:ion_dev: assigned reserved memory node linux,ion-dev Sep 01 13:18:31 ict kernel: ge2d: ge2d_init_module Sep 01 13:18:31 ict kernel: ge2d: ge2d_dev major:236 Sep 01 13:18:31 ict kernel: ge2d: clock source clk_ge2d_gate ffffffc0ca1596c0 Sep 01 13:18:31 ict kernel: ge2d: clock clk_ge2d source ffffffc0ca159740 Sep 01 13:18:31 ict kernel: ge2d: clock source clk_vapb_0 ffffffc0ca159fc0 Sep 01 13:18:31 ict kernel: ge2d: ge2d init clock is 500000000 HZ, VPU clock is 666666656 HZ Sep 01 13:18:31 ict kernel: ge2d: ge2d clock is 499 MHZ Sep 01 13:18:31 ict kernel: ge2d: find address resource Sep 01 13:18:31 ict kernel: ge2d: map io source 0x00000000ff940000,size=65536 to 0xffffff8008690000 Sep 01 13:18:31 ict kernel: ge2d: reserved mem init failed Sep 01 13:18:31 ict kernel: ge2d: ge2d: pdev=ffffffc0ca1d4800, irq=41, clk=ffffffc0ca1596c0 Sep 01 13:18:31 ict kernel: ge2d: ge2d start monitor Sep 01 13:18:31 ict kernel: ge2d: ge2d workqueue monitor start Sep 01 13:18:31 ict kernel: [tsync_pcr_init]init success. Sep 01 13:18:31 ict kernel: amvideom vsync irq: 42 Sep 01 13:18:31 ict kernel: create_ge2d_work_queue video task ok Sep 01 13:18:31 ict kernel: fb: osd_init_module Sep 01 13:18:31 ict kernel: fb: viu vsync irq: 42 Sep 01 13:18:31 ict kernel: fb: viu2 vsync irq: 58 Sep 01 13:18:31 ict kernel: 0x000000db:Y=db,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000dc:Y=dc,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000dd:Y=dd,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000de:Y=de,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000df:Y=df,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000e0:Y=e0,U=0,V=0 Sep 01 13:18:31 ict kernel: fb: osd_rdma_init: rdma_table p=0xcf608000,op=0xcf608000 , v=0xffffff8008635000 Sep 01 13:18:31 ict kernel: rdma_register, rdma_table_addr ffffff8008637000 rdma_table_addr_phy cf609000 reg_buf ffffffc0ca2a7000 Sep 01 13:18:31 ict kernel: rdma_register success, handle 2 table_size 4096 Sep 01 13:18:31 ict kernel: fb: osd_rdma_init:osd rdma handle = 2. Sep 01 13:18:31 ict kernel: fb: mem_size: 0x800000 Sep 01 13:18:31 ict kernel: fb: mem_size: 0x4b80000 Sep 01 13:18:31 ict kernel: fb: mem_size: 0x100000 Sep 01 13:18:31 ict kernel: fb: mem_size: 0x100000 Sep 01 13:18:31 ict kernel: fb: mem_size: 0x800000 Sep 01 13:18:31 ict kernel: fb: failed to init reserved memory Sep 01 13:18:31 ict kernel: fb: fb def : 1920 1080 1920 2160 32 Sep 01 13:18:31 ict kernel: fb: init fbdev bpp is:32 Sep 01 13:18:31 ict kernel: fb: malloc_osd_memory, cma:ffffff800a8a1b30 Sep 01 13:18:31 ict kernel: fb: malloc_osd_memory, 1231, base:0x00000000cf400000, size:8388608 Sep 01 13:18:31 ict kernel: fb: use ion buffer for fb memory, fb_index=0 Sep 01 13:18:31 ict kernel: fb: OSD0 as afbcd mode,afbc_type=2 Sep 01 13:18:31 ict kernel: meson-fb meson-fb: create ion_client ffffffc0221e0000, handle=ffffffc0ca2c3b40 Sep 01 13:18:31 ict kernel: meson-fb meson-fb: ion memory(0): created fb at 0x00000000e5800000, size 75 MiB Sep 01 13:18:31 ict kernel: fb: 0, phy: 0x00000000e5800000, vir:0xffffff800a94f000, size=77312K Sep 01 13:18:31 ict kernel: fb: Frame buffer memory assigned at Sep 01 13:18:31 ict kernel: fb: 0, phy: 0x00000000e5800000, vir:0xffffff800a94f000, size=77312K Sep 01 13:18:31 ict kernel: fb: 0, phy: 0x00000000e5800000, vir:0xffffff800a94f000, size=77312K Sep 01 13:18:31 ict kernel: fb: logo_index=0,fb_index=0 Sep 01 13:18:31 ict kernel: fb: ---------------clear fb0 memory ffffff800a94f000 Sep 01 13:18:31 ict kernel: fb: osd[0] canvas.idx =0x40 Sep 01 13:18:31 ict kernel: fb: osd[0] canvas.addr=0xe5800000 Sep 01 13:18:31 ict kernel: fb: osd[0] canvas.width=7680 Sep 01 13:18:31 ict kernel: fb: osd[0] canvas.height=2160 Sep 01 13:18:31 ict kernel: fb: osd[0] frame.width=1920 Sep 01 13:18:31 ict kernel: fb: osd[0] frame.height=1080 Sep 01 13:18:31 ict kernel: fb: osd[0] out_addr_id =0x1 Sep 01 13:18:31 ict kernel: clear:c5000000, free:c5000000, tick:683469 us Sep 01 13:18:31 ict kernel: Console: switching to colour frame buffer device 240x67 Sep 01 13:18:31 ict kernel: fb: osd[0] enable: 1 (swapper/0) Sep 01 13:18:31 ict kernel: fb: set osd0 reverse as NONE Sep 01 13:18:31 ict kernel: fb: osd probe OK Sep 01 13:18:31 ict kernel: hdmitx: hdcp: hdmitx_hdcp_init Sep 01 13:18:31 ict kernel: vout: vout2: create vout2 attribute OK Sep 01 13:18:31 ict kernel: vout: vout2: vout2_fops_create OK Sep 01 13:18:31 ict kernel: vout: vout2: clktree_init Sep 01 13:18:31 ict kernel: vout: vout2: register server: nulldisp_vout2_server Sep 01 13:18:31 ict kernel: vout: vout2: init mode null set ok Sep 01 13:18:31 ict kernel: vout: vout2: aml_vout2_probe OK Sep 01 13:18:31 ict kernel: DI: di_module_init ok. Sep 01 13:18:31 ict kernel: DI: di_probe: Sep 01 13:18:31 ict kernel: DI: di_probe: major 510 Sep 01 13:18:31 ict kernel: deinterlace deinterlace: assigned reserved memory node linux,di_cma Sep 01 13:18:31 ict kernel: di:flag_cma=1 Sep 01 13:18:31 ict kernel: DI: CMA size 0x2800000. Sep 01 13:18:31 ict kernel: pre_irq:56 Sep 01 13:18:31 ict kernel: post_irq:57 Sep 01 13:18:31 ict kernel: DI: di_probe allocate rdma channel 0. Sep 01 13:18:31 ict kernel: di_get_vpu_clkb: get clk vpu error. Sep 01 13:18:31 ict kernel: DI: vpu clkb <334000000, 667000000> Sep 01 13:18:31 ict kernel: get clkb rate:333333328 Sep 01 13:18:31 ict kernel: DI:enable vpu clkb. Sep 01 13:18:31 ict kernel: 0x000000e1:Y=e1,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000e2:Y=e2,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000e3:Y=e3,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f0:Y=f0,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f1:Y=f1,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f2:Y=f2,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f3:Y=f3,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f4:Y=f4,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f5:Y=f5,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f6:Y=f6,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f7:Y=f7,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f8:Y=f8,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000f9:Y=f9,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000fa:Y=fa,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000fb:Y=fb,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000fc:Y=fc,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000fd:Y=fd,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000fe:Y=fe,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x000000ff:Y=ff,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003a:Y=3a,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003b:Y=3b,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003c:Y=3c,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003d:Y=3d,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003e:Y=3e,U=0,V=0 Sep 01 13:18:31 ict kernel: 0x0000003f:Y=3f,U=0,V=0 Sep 01 13:18:31 ict kernel: DI: support multi decoding 61~62~63. Sep 01 13:18:31 ict kernel: DI: di_probe:Di use HRTIMER Sep 01 13:18:31 ict kernel: DI: di_probe:ok Sep 01 13:18:31 ict kernel: dim:dim_module_init Sep 01 13:18:31 ict kernel: dim:dim_module_init finish Sep 01 13:18:31 ict kernel: dil:dil_init. Sep 01 13:18:31 ict kernel: dil:dil_init ok. Sep 01 13:18:31 ict kernel: vdin_drv_init: major 509 Sep 01 13:18:31 ict kernel: vdin_drv_init: vdin driver init done Sep 01 13:18:31 ict kernel: [viuin..]viuin_init_module viuin module init Sep 01 13:18:31 ict kernel: [viuin..]viuin_probe probe ok. Sep 01 13:18:31 ict kernel: [RX]-hdmirx: hdmirx_init. Sep 01 13:18:31 ict kernel: ESM HLD: Initializing... Sep 01 13:18:31 ict kernel: amlvid:info: amlvideo_init called Sep 01 13:18:31 ict kernel: amlvid:info: amlvideo_create_instance called Sep 01 13:18:31 ict kernel: amlvid:info: v4l2_dev.name=:amlvideo-000 Sep 01 13:18:31 ict kernel: amlvideo-000: V4L2 device registered as video10 Sep 01 13:18:31 ict kernel: amlvid:info: amlvideo_create_instance called Sep 01 13:18:31 ict kernel: amlvid:info: v4l2_dev.name=:amlvideo-001 Sep 01 13:18:31 ict kernel: amlvideo-001: V4L2 device registered as video23 Sep 01 13:18:31 ict kernel: PPMGRDRV: warn: ppmgr module init func called Sep 01 13:18:31 ict kernel: PPMGRDRV: info: ppmgr_driver_probe called Sep 01 13:18:31 ict kernel: Reserved memory: failed to init DMA memory pool at 0x00000000ed800000, size 0 MiB Sep 01 13:18:31 ict kernel: PPMGRDRV: info: ppmgr_dev major:507 Sep 01 13:18:31 ict kernel: ionvideo-000: V4L2 device registered as video13 Sep 01 13:18:31 ict kernel: ionvideo-001: V4L2 device registered as video14 Sep 01 13:18:31 ict kernel: ionvideo-002: V4L2 device registered as video15 Sep 01 13:18:31 ict kernel: ionvideo-003: V4L2 device registered as video16 Sep 01 13:18:31 ict kernel: ionvideo-004: V4L2 device registered as video17 Sep 01 13:18:31 ict kernel: ionvideo-005: V4L2 device registered as video18 Sep 01 13:18:31 ict kernel: ionvideo-006: V4L2 device registered as video19 Sep 01 13:18:31 ict kernel: ionvideo-007: V4L2 device registered as video20 Sep 01 13:18:31 ict kernel: ionvideo-008: V4L2 device registered as video21 Sep 01 13:18:31 ict kernel: ionvid: info: Video Technology Magazine Ion Video Sep 01 13:18:31 ict kernel: ionvid: info: Capture Board ver 1.0 successfully loaded Sep 01 13:18:31 ict kernel: videosync_create_instance dev_s ffffffc022273c00,dev_s->dev ffffffc0221d0880 Sep 01 13:18:31 ict kernel: videosync_create_instance reg videosync.0 Sep 01 13:18:31 ict kernel: aml_vecm_init:module init Sep 01 13:18:31 ict kernel: videosync_thread started Sep 01 13:18:31 ict kernel: VECM probe start Sep 01 13:18:31 ict kernel: Can't find detect_colorbar. Sep 01 13:18:31 ict kernel: Can't find detect_face. Sep 01 13:18:31 ict kernel: Can't find detect_corn. Sep 01 13:18:31 ict kernel: Can't find wb_sel. Sep 01 13:18:31 ict kernel: hdr:Can't find cfg_en_osd_100. Sep 01 13:18:31 ict kernel: amlogic, vecm Sep 01 13:18:31 ict kernel: vlock dt support: 1 Sep 01 13:18:31 ict kernel: vlock dt new_fsm: 0 Sep 01 13:18:31 ict kernel: vlock dt hwver: 0 Sep 01 13:18:31 ict kernel: vlock dt phlock_en: 0 Sep 01 13:18:31 ict kernel: Can't find vlock_en. Sep 01 13:18:31 ict kernel: Can't find vlock_mode. Sep 01 13:18:31 ict kernel: Can't find vlock_pll_m_limit. Sep 01 13:18:31 ict kernel: Can't find vlock_line_limit. Sep 01 13:18:31 ict kernel: param_config vlock_en:1 md=0x4 Sep 01 13:18:31 ict kernel: vlock: maxLine 524,maxPixel 1715 Sep 01 13:18:31 ict kernel: vlock_status_init vlock_en:1 Sep 01 13:18:31 ict kernel: aml_vecm_probe: ok Sep 01 13:18:31 ict kernel: amdolby_vision_init:module init Sep 01 13:18:31 ict kernel: amdolby_vision probe start & ver: 20181220 Sep 01 13:18:31 ict kernel: cpu_id=2 tvmode=0 Sep 01 13:18:31 ict kernel: dolby_vision_init_receiver(dvel) Sep 01 13:18:31 ict kernel: dolby_vision_init_receiver: dvel Sep 01 13:18:31 ict kernel: amdolby_vision_probe: ok Sep 01 13:18:31 ict kernel: dovi disable in uboot Sep 01 13:18:31 ict kernel: meson-mmc: mmc driver version: 3.02, 2017-05-15: New Emmc Host Controller Sep 01 13:18:31 ict kernel: meson-mmc: >>>>>>>>hostbase ffffff80086b7000, dmode Sep 01 13:18:31 ict kernel: meson-mmc: actual_clock :400000, HHI_nand: 0x80 Sep 01 13:18:31 ict kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000033c Sep 01 13:18:31 ict kernel: hdmitx: hdmitx_set_drm_pkt: tf=1, cf=1, colormetry=0 Sep 01 13:18:31 ict kernel: meson-mmc: meson_mmc_probe() : success! Sep 01 13:18:31 ict kernel: meson-mmc: >>>>>>>>hostbase ffffff80086c0000, dmode Sep 01 13:18:31 ict kernel: meson-mmc: gpio_cd = 1ca Sep 01 13:18:31 ict kernel: meson-mmc: emmc: resp_timeout,vstat:0xa1ff2800,virqc:3fff Sep 01 13:18:31 ict kernel: meson-mmc: emmc: err: wait for irq service, bus_fsm:0x8 Sep 01 13:18:31 ict kernel: meson-mmc: meson_mmc_irq_thread_v3() 653: set 1st retry! Sep 01 13:18:31 ict kernel: meson-mmc: retry cmd 1 the 3-th time(s) Sep 01 13:18:31 ict kernel: meson-mmc: emmc: resp_timeout,vstat:0xa1ff2800,virqc:3fff Sep 01 13:18:31 ict kernel: meson-mmc: emmc: err: wait for irq service, bus_fsm:0x8 Sep 01 13:18:31 ict kernel: meson-mmc: retry cmd 1 the 2-th time(s) Sep 01 13:18:31 ict kernel: meson-mmc: emmc: resp_timeout,vstat:0xa1ff2800,virqc:3fff Sep 01 13:18:31 ict kernel: meson-mmc: emmc: err: wait for irq service, bus_fsm:0x8 Sep 01 13:18:31 ict kernel: meson-mmc: retry cmd 1 the 1-th time(s) Sep 01 13:18:31 ict kernel: meson-mmc: emmc: resp_timeout,vstat:0xa1ff2800,virqc:3fff Sep 01 13:18:31 ict kernel: meson-mmc: emmc: err: wait for irq service, bus_fsm:0x8 Sep 01 13:18:31 ict kernel: meson-mmc: Command retried failed line:675, cmd:1 Sep 01 13:18:31 ict kernel: meson-mmc: meson_mmc_probe() : success! Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: cec driver date:2019/10/22: finetune ARB rising time Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: compatible:amlogic, aocec-sm1 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: cecb_ver:0x2 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: line_reg:0x1 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: line_bit:0x3 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: ee_to_ao:0x1 Sep 01 13:18:31 ict kernel: input: cec_input as /devices/virtual/input/input0 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: not find 'port_num' Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: using cec:1 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: no hdmirx regs Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: no hhi regs Sep 01 13:18:31 ict kernel: irq cnt:2, a:40, b39 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: wakeup_reason:0x0 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: cev val1: 0x0;val2: 0x0 Sep 01 13:18:31 ict kernel: cectx ff80023c.aocec: aml_cec_probe success end Sep 01 13:18:31 ict kernel: unifykey: storage in base: 0xffffffc005000000 Sep 01 13:18:31 ict kernel: unifykey: storage out base: 0xffffffc005040000 Sep 01 13:18:31 ict kernel: unifykey: storage block base: 0xffffffc005080000 Sep 01 13:18:31 ict kernel: unifykey: probe done! Sep 01 13:18:31 ict kernel: unifykey: no efuse-version set, use default value: -1 Sep 01 13:18:31 ict kernel: unifykey: key unify config unifykey-num is 14 Sep 01 13:18:31 ict kernel: unifykey: key unify fact unifykey-num is 17 Sep 01 13:18:31 ict kernel: unifykey: unifykey_devno: 1f600000 Sep 01 13:18:31 ict kernel: unifykey: device unifykeys created ok Sep 01 13:18:31 ict kernel: unifykey: aml_unifykeys_init done! Sep 01 13:18:31 ict kernel: meson ts init Sep 01 13:18:31 ict kernel: tsensor id: 0 Sep 01 13:18:31 ict kernel: r1p1_tsensor_read valid cnt is 0 Sep 01 13:18:31 ict kernel: tsensor trim info: 0xfa008009! Sep 01 13:18:31 ict kernel: tsensor hireboot: 0xc0ff2a80 Sep 01 13:18:31 ict kernel: meson ts init Sep 01 13:18:31 ict kernel: tsensor id: 1 Sep 01 13:18:31 ict kernel: r1p1_tsensor_read valid cnt is 0 Sep 01 13:18:31 ict kernel: tsensor trim info: 0xfa00802a! Sep 01 13:18:31 ict kernel: tsensor hireboot: 0xc0ff2a90 Sep 01 13:18:31 ict kernel: audio_dsp: [dsp]register dsp to char divece(257) Sep 01 13:18:31 ict kernel: amaudio: amaudio: driver amaudio init! Sep 01 13:18:31 ict kernel: amaudio: amaudio_init - amaudio: driver amaudio succuess! Sep 01 13:18:31 ict kernel: amlkaraoke init success! Sep 01 13:18:31 ict kernel: sysled: module init Sep 01 13:18:31 ict kernel: meson_wdt ffd0f0d0.watchdog: start watchdog Sep 01 13:18:31 ict kernel: meson_wdt ffd0f0d0.watchdog: creat work queue for watch dog Sep 01 13:18:31 ict kernel: meson_wdt ffd0f0d0.watchdog: AML Watchdog Timer probed done Sep 01 13:18:31 ict kernel: meson-saradc ff809000.saradc: set delay per tick to <1ms> by default. Sep 01 13:18:31 ict kernel: meson-saradc ff809000.saradc: set ticks per period to <1> by default. Sep 01 13:18:31 ict kernel: dmc_monitor_probe Sep 01 13:18:31 ict kernel: atv_demod: aml_atvdemod_init: OK, atv demod version: V2.15. Sep 01 13:18:31 ict kernel: defendkey ff630218.defendkey: Reserved memory is not enough! Sep 01 13:18:31 ict kernel: defendkey: probe of ff630218.defendkey failed with error -22 Sep 01 13:18:31 ict kernel: usbcore: registered new interface driver snd-usb-audio Sep 01 13:18:31 ict kernel: Error: Driver 'spdif-dit' is already registered, aborting... Sep 01 13:18:31 ict kernel: asoc debug: aml_audio_controller_probe-130 Sep 01 13:18:31 ict kernel: aml_spdif_platform_probe, spdif ID = 0 Sep 01 13:18:31 ict kernel: SPDIF id 0 asrc_id:0 auto_asrc:0 Sep 01 13:18:31 ict kernel: spdifout_play_with_zerodata, spdif id:0 enable:0 Sep 01 13:18:31 ict kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Sep 01 13:18:31 ict kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 Sep 01 13:18:31 ict kernel: hdmitx: audio: aout notify format CT_PCM Sep 01 13:18:31 ict kernel: spdif_a is set to enable Sep 01 13:18:31 ict kernel: aml_spdif_platform_probe, register soc platform Sep 01 13:18:31 ict kernel: audio-ddr-manager ff660000.audiobus:ddr_manager: 0, irqs toddr 27, frddr 31 Sep 01 13:18:31 ict kernel: audio-ddr-manager ff660000.audiobus:ddr_manager: 1, irqs toddr 28, frddr 32 Sep 01 13:18:31 ict kernel: audio-ddr-manager ff660000.audiobus:ddr_manager: 2, irqs toddr 29, frddr 33 Sep 01 13:18:31 ict kernel: audio-ddr-manager ff660000.audiobus:ddr_manager: 3, irqs toddr 30, frddr 34 Sep 01 13:18:31 ict kernel: audiolocker_platform_probe Sep 01 13:18:31 ict kernel: Register vad Sep 01 13:18:31 ict kernel: aml_dai_spdif_probe Sep 01 13:18:31 ict kernel: set normal 512 fs /4 fs Sep 01 13:18:31 ict kernel: set spdifout clk:6144000, mpll:24576000 Sep 01 13:18:31 ict kernel: get spdifout clk:6143997, mpll:24575987 Sep 01 13:18:31 ict kernel: aml_dai_set_spdif_fmt , fmt 0x4010 Sep 01 13:18:31 ict kernel: aml_spdif_new spdif_a, clk continuous:1 Sep 01 13:18:31 ict kernel: spdifout_play_with_zerodata_free, spdif id:0 Sep 01 13:18:31 ict kernel: asoc-aml-card odroid_hdmi: dit-hifi <-> SPDIF mapping ok Sep 01 13:18:31 ict kernel: snd_card_add_kcontrols card:ffffffc02226e018 Sep 01 13:18:31 ict kernel: effect_v2 is not init Sep 01 13:18:31 ict kernel: Not init vad Sep 01 13:18:31 ict kernel: Failed to add VAD controls Sep 01 13:18:31 ict kernel: eq/drc v1 function enable Sep 01 13:18:31 ict kernel: no node audio_effect for eq/drc info! Sep 01 13:18:31 ict kernel: Failed to add audio effects v1 controls Sep 01 13:18:31 ict kernel: Netfilter messages via NETLINK v0.30. Sep 01 13:18:31 ict kernel: Initializing XFRM netlink socket Sep 01 13:18:31 ict kernel: NET: Registered protocol family 17 Sep 01 13:18:31 ict kernel: Key type dns_resolver registered Sep 01 13:18:31 ict kernel: Registered swp emulation handler Sep 01 13:18:31 ict kernel: Registered cp15_barrier emulation handler Sep 01 13:18:31 ict kernel: Registered setend emulation handler Sep 01 13:18:31 ict kernel: disable EAS feature Sep 01 13:18:31 ict kernel: registered taskstats version 1 Sep 01 13:18:31 ict kernel: dwc3 ff500000.dwc3: Configuration mismatch. dr_mode forced to host Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: xHCI Host Controller Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 1 Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: hcc params 0x0228fe6c hci version 0x110 quirks 0x20010010 Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: irq 22, io mem 0xff500000 Sep 01 13:18:31 ict kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002 Sep 01 13:18:31 ict kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 01 13:18:31 ict kernel: usb usb1: Product: xHCI Host Controller Sep 01 13:18:31 ict kernel: usb usb1: Manufacturer: Linux 4.9.241+ xhci-hcd Sep 01 13:18:31 ict kernel: usb usb1: SerialNumber: xhci-hcd.0.auto Sep 01 13:18:31 ict kernel: hub 1-0:1.0: USB hub found Sep 01 13:18:31 ict kernel: hub 1-0:1.0: 2 ports detected Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: xHCI Host Controller Sep 01 13:18:31 ict kernel: xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 2 Sep 01 13:18:31 ict kernel: usb usb2: We don't know the algorithms for LPM for this host, disabling LPM. Sep 01 13:18:31 ict kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003 Sep 01 13:18:31 ict kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Sep 01 13:18:31 ict kernel: usb usb2: Product: xHCI Host Controller Sep 01 13:18:31 ict kernel: usb usb2: Manufacturer: Linux 4.9.241+ xhci-hcd Sep 01 13:18:31 ict kernel: usb usb2: SerialNumber: xhci-hcd.0.auto Sep 01 13:18:31 ict kernel: hub 2-0:1.0: USB hub found Sep 01 13:18:31 ict kernel: hub 2-0:1.0: 1 port detected Sep 01 13:18:31 ict kernel: hctosys: unable to open rtc device (rtc0) Sep 01 13:18:31 ict kernel: dwc_otg ff400000.dwc2_a: dwc_otg_driver_probe(ffffffc0ca0a8c00) Sep 01 13:18:31 ict kernel: dwc_otg: usb0: type: 2 speed: 0, config: 0, dma: 0, id: 0, phy: ffe09000, ctrl: 0 Sep 01 13:18:31 ict kernel: dwc_otg ff400000.dwc2_a: base=0xffffff8008b40000 Sep 01 13:18:31 ict kernel: dwc_otg ff400000.dwc2_a: dwc_otg_device=0xffffffc0223b4200 Sep 01 13:18:31 ict kernel: dwc_otg: Core Release: 3.30a Sep 01 13:18:31 ict kernel: dwc_otg: Setting default values for core params Sep 01 13:18:31 ict kernel: dwc_otg: curmode: 0, host_only: 0 Sep 01 13:18:31 ict kernel: dwc_otg ff400000.dwc2_a: DMA config: BURST_DEFAULT Sep 01 13:18:31 ict kernel: dwc_otg: Using Buffer DMA mode Sep 01 13:18:31 ict kernel: dwc_otg: OTG VER PARAM: 1, OTG VER FLAG: 1 Sep 01 13:18:31 ict kernel: dwc_otg: Working on port type = SLAVE Sep 01 13:18:31 ict kernel: dwc_otg: Dedicated Tx FIFOs mode Sep 01 13:18:31 ict kernel: meson_cdev probe Sep 01 13:18:31 ict kernel: thermal: read gpupp failed Sep 01 13:18:31 ict kernel: meson_cdev index: 0 Sep 01 13:18:31 ict kernel: thermal: read gpupp failed Sep 01 13:18:31 ict kernel: meson_cdev index: 1 Sep 01 13:18:31 ict kernel: cpucore_cooling_register, max_cpu_core_num:4 Sep 01 13:18:31 ict kernel: meson_cdev index: 2 Sep 01 13:18:31 ict kernel: thermal: read gpupp failed Sep 01 13:18:31 ict kernel: meson_cdev index: 3 Sep 01 13:18:31 ict kernel: find tzd id: 0 Sep 01 13:18:31 ict kernel: find tzd id: 0 Sep 01 13:18:31 ict kernel: meson_cdev probe done Sep 01 13:18:31 ict kernel: gxbb_pm: enter meson_pm_probe! Sep 01 13:18:31 ict kernel: no vddio3v3_en pin Sep 01 13:18:31 ict kernel: pm-meson aml_pm: Can't get switch_clk81 Sep 01 13:18:31 ict kernel: gxbb_pm: meson_pm_probe done Sep 01 13:18:31 ict kernel: ALSA device list: Sep 01 13:18:31 ict kernel: #0: ODROID-HDMI Sep 01 13:18:31 ict kernel: meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 115200 to 115200 Sep 01 13:18:31 ict kernel: Freeing unused kernel memory: 4992K Sep 01 13:18:31 ict kernel: meson-mmc: card IN Sep 01 13:18:31 ict kernel: meson-mmc: normal card in Sep 01 13:18:31 ict kernel: meson-mmc: actual_clock :400000, HHI_nand: 0x80 Sep 01 13:18:31 ict kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000033c Sep 01 13:18:31 ict kernel: usb 1-1: new high-speed USB device number 2 using xhci-hcd Sep 01 13:18:31 ict kernel: meson-mmc: actual_clock :400000, HHI_nand: 0x80 Sep 01 13:18:31 ict kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x1000033c Sep 01 13:18:31 ict kernel: meson-aml-mmc ffe05000.sd: divider requested rate 200000000 != actual rate 199999997: ret=0 Sep 01 13:18:31 ict kernel: meson-mmc: actual_clock :199999997, HHI_nand: 0x80 Sep 01 13:18:31 ict kernel: meson-mmc: [meson_mmc_clk_set_rate_v3] after clock: 0x10000245 Sep 01 13:18:31 ict kernel: meson-mmc: Data 1 aligned delay is 0 Sep 01 13:18:31 ict kernel: meson-mmc: sd: clk 199999997 tuning start Sep 01 13:18:31 ict kernel: meson-mmc: sd: adj_win: < 0 1 2 3 > Sep 01 13:18:31 ict kernel: meson-mmc: step:4, delay1:0x4104104, delay2:0x4004104 Sep 01 13:18:31 ict kernel: meson-mmc: sd: adj_win: < 0 1 2 3 > Sep 01 13:18:31 ict kernel: meson-mmc: step:8, delay1:0x8208208, delay2:0x8008208 Sep 01 13:18:31 ict kernel: usb 1-1: New USB device found, idVendor=2109, idProduct=2817 Sep 01 13:18:31 ict kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 01 13:18:31 ict kernel: usb 1-1: Product: USB2.0 Hub Sep 01 13:18:31 ict kernel: usb 1-1: Manufacturer: VIA Labs, Inc. Sep 01 13:18:31 ict kernel: meson-mmc: sd: adj_win: < 0 1 2 3 > Sep 01 13:18:31 ict kernel: meson-mmc: step:12, delay1:0xc30c30c, delay2:0xc00c30c Sep 01 13:18:31 ict kernel: meson-mmc: sd: adj_win: < 0 1 2 3 4 > Sep 01 13:18:31 ict kernel: meson-mmc: step:16, delay1:0x10410410, delay2:0x10010410 Sep 01 13:18:31 ict kernel: meson-mmc: sd: adj_win: < 1 2 3 4 > Sep 01 13:18:31 ict kernel: meson-mmc: left:3, right:0, mid:4, size:4 Sep 01 13:18:31 ict kernel: meson-mmc: step:0, delay1:0x0, delay2:0x0 Sep 01 13:18:31 ict kernel: meson-mmc: sd: sd_emmc_regs->gclock=0x10000245,sd_emmc_regs->gadjust=0x22000 Sep 01 13:18:31 ict kernel: meson-mmc: delay1:0x0, delay2:0x0 Sep 01 13:18:31 ict kernel: sd: new ultra high speed SDR104 SDXC card at address aaaa Sep 01 13:18:31 ict kernel: sd: clock 199999997, 4-bit-bus-width Sep 01 13:18:31 ict kernel: mmcblk1: sd:aaaa SC128 119 GiB Sep 01 13:18:31 ict kernel: mmcblk1: p1 p2 p3 Sep 01 13:18:31 ict kernel: hub 1-1:1.0: USB hub found Sep 01 13:18:31 ict kernel: hub 1-1:1.0: 4 ports detected Sep 01 13:18:31 ict kernel: usb 2-1: new SuperSpeed USB device number 2 using xhci-hcd Sep 01 13:18:31 ict kernel: usb 2-1: New USB device found, idVendor=2109, idProduct=0817 Sep 01 13:18:31 ict kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 01 13:18:31 ict kernel: usb 2-1: Product: USB3.0 Hub Sep 01 13:18:31 ict kernel: usb 2-1: Manufacturer: VIA Labs, Inc. Sep 01 13:18:31 ict kernel: hub 2-1:1.0: USB hub found Sep 01 13:18:31 ict kernel: hub 2-1:1.0: 4 ports detected Sep 01 13:18:31 ict kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Sep 01 13:18:31 ict kernel: usb 1-1.1: new full-speed USB device number 3 using xhci-hcd Sep 01 13:18:31 ict kernel: usb 1-1.1: New USB device found, idVendor=0d8c, idProduct=0014 Sep 01 13:18:31 ict kernel: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Sep 01 13:18:31 ict kernel: usb 1-1.1: Product: USB Audio Device Sep 01 13:18:31 ict kernel: usb 1-1.1: Manufacturer: C-Media Electronics Inc. Sep 01 13:18:31 ict kernel: input: C-Media Electronics Inc. USB Audio Device as /devices/platform/ff500000.dwc3/xhci-hcd.0.auto/usb1/1-1/1-1.1/1-1.1:1.3/0003:0D8C:0014.0001/input/input1 Sep 01 13:18:31 ict kernel: hid-generic 0003:0D8C:0014.0001: input,hidraw0: USB HID v1.00 Device [C-Media Electronics Inc. USB Audio Device] on usb-xhci-hcd.0.auto-1.1/input3 Sep 01 13:18:31 ict kernel: EXT4-fs (mmcblk1p2): recovery complete Sep 01 13:18:31 ict kernel: EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null) Sep 01 13:18:31 ict kernel: EXT4-fs (mmcblk1p3): recovery complete Sep 01 13:18:31 ict kernel: EXT4-fs (mmcblk1p3): mounted filesystem with ordered data mode. Opts: (null) Sep 01 13:18:31 ict systemd[1]: System time before build time, advancing clock. Sep 01 13:18:31 ict kernel: NET: Registered protocol family 10 Sep 01 13:18:31 ict kernel: ip_tables: (C) 2000-2006 Netfilter Core Team Sep 01 13:18:31 ict kernel: cgroup: cgroup2: unknown option "nsdelegate" Sep 01 13:18:31 ict 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) Sep 01 13:18:31 ict systemd[1]: Detected architecture arm64. Sep 01 13:18:31 ict systemd[1]: Set hostname to . Sep 01 13:18:31 ict systemd[1]: File /lib/systemd/system/systemd-journald.service:12 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling. Sep 01 13:18:31 ict systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.) Sep 01 13:18:31 ict 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. Sep 01 13:18:31 ict systemd[1]: Listening on initctl Compatibility Named Pipe. Sep 01 13:18:31 ict systemd[1]: Listening on fsck to fsckd communication Socket. Sep 01 13:18:31 ict systemd[1]: Created slice system-getty.slice. Sep 01 13:18:31 ict systemd[1]: Reached target System Time Synchronized. Sep 01 13:18:31 ict kernel: Removed cp15_barrier emulation handler Sep 01 13:18:31 ict kernel: Enabled cp15_barrier support Sep 01 13:18:31 ict kernel: RPC: Registered named UNIX socket transport module. Sep 01 13:18:31 ict kernel: RPC: Registered udp transport module. Sep 01 13:18:31 ict kernel: RPC: Registered tcp transport module. Sep 01 13:18:31 ict kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Sep 01 13:18:31 ict systemd-journald[2070]: Journal started Sep 01 13:18:31 ict systemd-journald[2070]: Runtime journal (/run/log/journal/af8878b85456c7d2e9b1aa7a6664d164) is 7.5M, max 30.0M, 22.5M free. Sep 01 13:18:31 ict fake-hwclock[2066]: Mon Sep 1 11:18:31 UTC 2025 Sep 01 13:18:31 ict systemd[1]: Started Create Static Device Nodes in /dev. Sep 01 13:18:31 ict systemd[1]: Reached target Local File Systems (Pre). Sep 01 13:18:31 ict systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway. Sep 01 13:18:31 ict systemd[1]: Mounting /tmp... Sep 01 13:18:31 ict systemd[1]: Mounting /var/spool/cups... Sep 01 13:18:31 ict systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway. Sep 01 13:18:31 ict systemd[1]: Mounting /var/log... Sep 01 13:18:31 ict systemd[1]: Starting udev Kernel Device Manager... Sep 01 13:18:31 ict systemd[1]: Mounted /tmp. Sep 01 13:18:31 ict systemd[1]: Mounted /var/spool/cups. Sep 01 13:18:31 ict systemd[1]: Mounting /var/spool/cups/tmp... Sep 01 13:18:31 ict systemd[1]: Mounted /var/log. Sep 01 13:18:31 ict systemd[1]: Starting Flush Journal to Persistent Storage... Sep 01 13:18:31 ict systemd[1]: Mounted /var/spool/cups/tmp. Sep 01 13:18:31 ict systemd[1]: Started udev Coldplug all Devices. Sep 01 13:18:31 ict systemd[1]: Starting Helper to synchronize boot up for ifupdown... Sep 01 13:18:31 ict systemd-udevd[2100]: Network interface NamePolicy= disabled on kernel command line, ignoring. Sep 01 13:18:31 ict systemd[1]: Started udev Kernel Device Manager. Sep 01 13:18:31 ict systemd[1]: Starting Show Plymouth Boot Screen... Sep 01 13:18:31 ict systemd-journald[2070]: Runtime journal (/run/log/journal/af8878b85456c7d2e9b1aa7a6664d164) is 7.5M, max 30.0M, 22.5M free. Sep 01 13:18:31 ict systemd[1]: Started Flush Journal to Persistent Storage. Sep 01 13:18:31 ict systemd[1]: plymouth-start.service: Succeeded. Sep 01 13:18:31 ict systemd[1]: Started Show Plymouth Boot Screen. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 01 13:18:31 ict systemd[1]: Reached target Local Encrypted Volumes. Sep 01 13:18:31 ict systemd[1]: Reached target Paths. Sep 01 13:18:31 ict systemd[1]: Started Forward Password Requests to Plymouth Directory Watch. Sep 01 13:18:31 ict kernel: vout: aml_tvout_mode_work: monitor_timeout Sep 01 13:18:31 ict systemd-udevd[2137]: Using default interface naming scheme 'v240'. Sep 01 13:18:31 ict kernel: register clk_set_setting cpu[43] Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 01 13:18:31 ict kernel: Registered firmware driver success. Sep 01 13:18:31 ict kernel: Try to load video/h264_enc.bin ... Sep 01 13:18:31 ict systemd[1]: Starting Show Plymouth Boot Screen... Sep 01 13:18:31 ict kernel: load firmware size : 76288, Name : video/h264_enc.bin. Sep 01 13:18:31 ict kernel: Try to load video/video_ucode.bin ... Sep 01 13:18:31 ict systemd[1]: Condition check resulted in FUSE Control File System being skipped. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 01 13:18:31 ict systemd-udevd[2137]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 01 13:18:31 ict systemd-udevd[2137]: link_config: could not get ethtool features for eth0 Sep 01 13:18:31 ict systemd-udevd[2137]: Could not set offload features of eth0: Device or resource busy Sep 01 13:18:31 ict systemd[1]: Found device /dev/ttyS0. Sep 01 13:18:31 ict kernel: load firmware size : 1816576, Name : video/video_ucode.bin. Sep 01 13:18:31 ict systemd-udevd[2123]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: Amlogic A/V streaming port init Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict kernel: get gate demux control ok ffffffc0c5891b40 Sep 01 13:18:31 ict kernel: get gate parser_top control ok ffffffc0c5891bc0 Sep 01 13:18:31 ict kernel: get gate vdec control ok ffffffc0c5891c40 Sep 01 13:18:31 ict kernel: get gate clk_81 control ok ffffffc0c5891cc0 Sep 01 13:18:31 ict kernel: get gate clk_vdec_mux control ok ffffffc0c5891d40 Sep 01 13:18:31 ict kernel: get gate clk_hcodec_mux control ok ffffffc0c5891dc0 Sep 01 13:18:31 ict kernel: get gate clk_hevc_mux control ok ffffffc0c5891e40 Sep 01 13:18:31 ict kernel: get gate clk_hevcb_mux control ok ffffffc0c5891ec0 Sep 01 13:18:31 ict kernel: get gate ahbarb0 control ok ffffffc0c5891f40 Sep 01 13:18:31 ict kernel: get gate asyncfifo control failed (null) Sep 01 13:18:31 ict kernel: ionvid: dbg: ionvideo open Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close!!!! Sep 01 13:18:31 ict kernel: ionvid: dbg: vidioc_close Sep 01 13:18:31 ict systemd[1]: plymouth-start.service: Succeeded. Sep 01 13:18:31 ict systemd[1]: Started Show Plymouth Boot Screen. Sep 01 13:18:31 ict kernel: decoder registered as /dev/video26 Sep 01 13:18:31 ict kernel: [0] vcodec_dec decoder Sep 01 13:18:31 ict kernel: [0] release decoder Sep 01 13:18:31 ict systemd-udevd[2131]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 01 13:18:31 ict systemd-udevd[2109]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Sep 01 13:18:31 ict systemd[1]: Found device /dev/disk/by-uuid/1E7D-6AB2. Sep 01 13:18:31 ict kernel: out of value, fixed it Sep 01 13:18:31 ict kernel: id=0 set inskew=0 Sep 01 13:18:31 ict systemd-udevd[2132]: Process '/bin/bash -c '/usr/local/bin/volumio scanaudioinputs'' failed with exit code 7. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped. Sep 01 13:18:31 ict systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Sep 01 13:18:31 ict systemd[1]: Starting Show Plymouth Boot Screen... Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Huge Pages File System being skipped. Sep 01 13:18:31 ict systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. Sep 01 13:18:32 ict systemd[1]: Condition check resulted in FUSE Control File System being skipped. Sep 01 13:18:32 ict systemd[1]: Starting File System Check on /dev/disk/by-uuid/1E7D-6AB2... Sep 01 13:18:32 ict systemd[1]: plymouth-start.service: Succeeded. Sep 01 13:18:32 ict systemd[1]: Started Show Plymouth Boot Screen. Sep 01 13:18:32 ict systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped. Sep 01 13:18:32 ict systemd[1]: Started File System Check Daemon to report status. Sep 01 13:18:32 ict systemd-fsck[2203]: fsck.fat 4.1 (2017-01-24) Sep 01 13:18:32 ict systemd-fsck[2203]: /dev/mmcblk1p1: 44 files, 43844/120958 clusters Sep 01 13:18:32 ict systemd[1]: Started File System Check on /dev/disk/by-uuid/1E7D-6AB2. Sep 01 13:18:32 ict systemd[1]: Mounting /boot... Sep 01 13:18:32 ict systemd[1]: Mounted /boot. Sep 01 13:18:32 ict systemd[1]: Reached target Local File Systems. Sep 01 13:18:32 ict systemd[1]: Starting Preprocess NFS configuration... Sep 01 13:18:32 ict systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped. Sep 01 13:18:32 ict systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Sep 01 13:18:32 ict systemd[1]: Starting Create Volatile Files and Directories... Sep 01 13:18:32 ict systemd[1]: Started ifup for eth0. Sep 01 13:18:32 ict systemd[1]: nfs-config.service: Succeeded. Sep 01 13:18:32 ict systemd[1]: Started Preprocess NFS configuration. Sep 01 13:18:32 ict systemd[1]: plymouth-read-write.service: Succeeded. Sep 01 13:18:32 ict systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Sep 01 13:18:32 ict systemd[1]: Received SIGRTMIN+20 from PID 1961 (plymouthd). Sep 01 13:18:32 ict systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped. Sep 01 13:18:32 ict systemd[1]: Condition check resulted in RPC security service for NFS server being skipped. Sep 01 13:18:32 ict systemd[1]: Reached target NFS client services. Sep 01 13:18:32 ict sh[2213]: command failed: No such device (-19) Sep 01 13:18:32 ict systemd[1]: Started Create Volatile Files and Directories. Sep 01 13:18:32 ict systemd[1]: Starting Update UTMP about System Boot/Shutdown... Sep 01 13:18:32 ict systemd[1]: Condition check resulted in Network Time Synchronization being skipped. Sep 01 13:18:32 ict systemd[1]: Started Entropy daemon using the HAVEGE algorithm. Sep 01 13:18:32 ict systemd[1]: Starting RPC bind portmap service... Sep 01 13:18:32 ict systemd[1]: Started Update UTMP about System Boot/Shutdown. Sep 01 13:18:32 ict systemd[1]: Reached target System Initialization. Sep 01 13:18:32 ict systemd[1]: Listening on triggerhappy.socket. Sep 01 13:18:32 ict systemd[1]: Started Daily apt download activities. Sep 01 13:18:32 ict systemd[1]: Started Daily apt upgrade and clean activities. Sep 01 13:18:32 ict systemd[1]: Listening on lircd.socket. Sep 01 13:18:32 ict systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket. Sep 01 13:18:32 ict systemd[1]: Listening on D-Bus System Message Bus Socket. Sep 01 13:18:32 ict systemd[1]: Reached target Sockets. Sep 01 13:18:32 ict systemd[1]: Reached target Basic System. Sep 01 13:18:32 ict systemd[1]: Starting triggerhappy global hotkey daemon... Sep 01 13:18:32 ict systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 13:18:32 ict systemd[1]: Starting Wireless Services... Sep 01 13:18:32 ict systemd[1]: Started Manage Sound Card State (restore and store). Sep 01 13:18:32 ict systemd[1]: Condition check resulted in Volumio SSH enabler being skipped. Sep 01 13:18:32 ict thd[2237]: Unable to parse trigger line: Sep 01 13:18:32 ict thd[2237]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle Sep 01 13:18:32 ict thd[2237]: Unable to parse trigger line: Sep 01 13:18:32 ict thd[2237]: Unable to parse trigger line: Sep 01 13:18:32 ict thd[2237]: Found socket passed from systemd Sep 01 13:18:32 ict systemd[1]: Started Volumio Iptables Module. Sep 01 13:18:32 ict systemd[1]: Started volumio-remote-updater.service. Sep 01 13:18:32 ict systemd[1]: Starting Save/Restore Sound Card State... Sep 01 13:18:32 ict systemd[1]: Starting Login Service... Sep 01 13:18:32 ict systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Sep 01 13:18:32 ict systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped. Sep 01 13:18:32 ict alsactl[2240]: alsactl 1.1.8 daemon started Sep 01 13:18:32 ict systemd[1]: Starting DHCP Client Daemon... Sep 01 13:18:32 ict systemd[1]: Started D-Bus System Message Bus. Sep 01 13:18:32 ict kernel: meson6-dwmac ff3f0000.ethernet eth0: fail to init PTP. Sep 01 13:18:32 ict systemd[1]: Starting WPA supplicant... Sep 01 13:18:32 ict systemd[1]: Starting lircd(8) initialization helper tool... Sep 01 13:18:32 ict systemd[1]: Started Daily Cleanup of Temporary Directories. Sep 01 13:18:32 ict systemd[1]: Reached target Timers. Sep 01 13:18:32 ict systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped. Sep 01 13:18:32 ict alsactl[2240]: /usr/sbin/alsactl: set_control:1461Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Sep 01 13:18:32 ict alsactl[2240]: /usr/sbin/alsactl: set_control:1461Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Sep 01 13:18:32 ict systemd[1]: Started Volumio Log Rotation Service. Sep 01 13:18:32 ict kernel: out of value, fixed it Sep 01 13:18:32 ict kernel: id=0 set inskew=0 Sep 01 13:18:32 ict systemd[1]: Started triggerhappy global hotkey daemon. Sep 01 13:18:32 ict systemd[1]: Started RPC bind portmap service. Sep 01 13:18:32 ict systemd[1]: Reached target Remote File Systems (Pre). Sep 01 13:18:32 ict systemd[1]: Reached target Remote File Systems. Sep 01 13:18:32 ict alsactl[2243]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Sep 01 13:18:32 ict alsactl[2243]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Sep 01 13:18:32 ict kernel: out of value, fixed it Sep 01 13:18:32 ict kernel: id=0 set inskew=0 Sep 01 13:18:32 ict systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling... Sep 01 13:18:32 ict systemd[1]: Reached target RPC Port Mapper. Sep 01 13:18:32 ict systemd[1]: Started Save/Restore Sound Card State. Sep 01 13:18:32 ict systemd[1]: Reached target Sound Card. Sep 01 13:18:32 ict kernel: 8021q: 802.1Q VLAN Support v1.8 Sep 01 13:18:32 ict kernel: nf_tables: (c) 2007-2009 Patrick McHardy Sep 01 13:18:32 ict kernel: nf_tables_compat: (c) 2012 Pablo Neira Ayuso Sep 01 13:18:32 ict avahi-daemon[2245]: Found user 'avahi' (UID 111) and group 'avahi' (GID 113). Sep 01 13:18:32 ict avahi-daemon[2245]: Successfully dropped root privileges. Sep 01 13:18:32 ict avahi-daemon[2245]: avahi-daemon 0.7 starting up. Sep 01 13:18:32 ict systemd-logind[2244]: Watching system buttons on /dev/input/event0 (cec_input) Sep 01 13:18:32 ict systemd-logind[2244]: New seat seat0. Sep 01 13:18:32 ict kernel: nf_conntrack version 0.5.0 (16384 buckets, 65536 max) Sep 01 13:18:32 ict systemd[1]: Started Helper to synchronize boot up for ifupdown. Sep 01 13:18:32 ict avahi-daemon[2245]: Successfully called chroot(). Sep 01 13:18:32 ict avahi-daemon[2245]: Successfully dropped remaining capabilities. Sep 01 13:18:32 ict avahi-daemon[2245]: Loading service file /services/volumio.service. Sep 01 13:18:32 ict avahi-daemon[2245]: Network interface enumeration completed. Sep 01 13:18:32 ict avahi-daemon[2245]: Server startup complete. Host name is ict.local. Local service cookie is 3553295512. Sep 01 13:18:32 ict avahi-daemon[2245]: Service "ICT" (/services/volumio.service) successfully established. Sep 01 13:18:32 ict systemd[1]: Started Login Service. Sep 01 13:18:32 ict systemd[1]: Started Avahi mDNS/DNS-SD Stack. Sep 01 13:18:32 ict dhcpcd[2246]: no interfaces have a carrier Sep 01 13:18:32 ict dhcpcd[2246]: no interfaces have a carrier Sep 01 13:18:32 ict volumio-remote-updater[2242]: Error: No active session Sep 01 13:18:32 ict systemd[1]: Starting Raise network interfaces... Sep 01 13:18:32 ict volumio-remote-updater[2242]: [2025-09-01 13:18:32] [info] asio async_connect error: system:111 (Connection refused) Sep 01 13:18:32 ict volumio-remote-updater[2242]: [2025-09-01 13:18:32] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Sep 01 13:18:32 ict volumio-remote-updater[2242]: [2025-09-01 13:18:32] [error] handle_connect error: Underlying Transport Error Sep 01 13:18:32 ict dhcpcd[2246]: forked to background, child pid 2307 Sep 01 13:18:32 ict dhcpcd[2246]: forked to background, child pid 2307 Sep 01 13:18:32 ict systemd[1]: Started DHCP Client Daemon. Sep 01 13:18:32 ict dhcpcd[2307]: eth0: waiting for carrier Sep 01 13:18:32 ict systemd[1]: Started WPA supplicant. Sep 01 13:18:32 ict wpa_supplicant[2249]: Successfully initialized wpa_supplicant Sep 01 13:18:32 ict sh[2213]: eth0=eth0 Sep 01 13:18:32 ict volumio[2238]: Could not open config: /tmp/upmpdcli.conf Sep 01 13:18:32 ict systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Sep 01 13:18:32 ict systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Sep 01 13:18:32 ict ifup[2305]: command failed: No such device (-19) Sep 01 13:18:33 ict ifup[2305]: command failed: No such device (-19) Sep 01 13:18:33 ict ifup[2305]: command failed: No such device (-19) Sep 01 13:18:33 ict lircd-setup[2251]: /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. Sep 01 13:18:33 ict lircd-setup[2251]: parser = configparser.SafeConfigParser() Sep 01 13:18:33 ict systemd[1]: lircd-setup.service: Succeeded. Sep 01 13:18:33 ict systemd[1]: Started lircd(8) initialization helper tool. Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, cma:ffffff800a8a1b30 Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, 1231, base:0x00000000cf400000, size:8388608 Sep 01 13:18:33 ict kernel: fb: use ion buffer for fb memory, fb_index=1 Sep 01 13:18:33 ict kernel: fb: OSD1 as afbcd mode,afbc_type=2 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: create ion_client ffffffc0221e0000, handle=ffffffc0c5173cc0 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: ion memory(1): created fb at 0x00000000ea400000, size 1 MiB Sep 01 13:18:33 ict kernel: fb: 1, phy: 0x00000000ea400000, vir:0xffffff800f8b6000, size=1024K Sep 01 13:18:33 ict kernel: fb: Frame buffer memory assigned at Sep 01 13:18:33 ict kernel: fb: 1, phy: 0x00000000ea400000, vir:0xffffff800f8b6000, size=1024K Sep 01 13:18:33 ict kernel: fb: 1, phy: 0x00000000ea400000, vir:0xffffff800f8b6000, size=1024K Sep 01 13:18:33 ict kernel: fb: logo_index=0,fb_index=1 Sep 01 13:18:33 ict kernel: fb: ---------------clear fb1 memory ffffff800f8b6000 Sep 01 13:18:33 ict kernel: fb: osd[1] canvas.idx =0x43 Sep 01 13:18:33 ict kernel: fb: osd[1] canvas.addr=0xea400000 Sep 01 13:18:33 ict kernel: fb: osd[1] canvas.width=128 Sep 01 13:18:33 ict kernel: fb: osd[1] canvas.height=32 Sep 01 13:18:33 ict kernel: fb: osd[1] frame.width=32 Sep 01 13:18:33 ict kernel: fb: osd[1] frame.height=32 Sep 01 13:18:33 ict kernel: fb: osd[1] out_addr_id =0x2 Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, cma:ffffff800a8a1b30 Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, 1231, base:0x00000000cf400000, size:8388608 Sep 01 13:18:33 ict kernel: fb: use ion buffer for fb memory, fb_index=2 Sep 01 13:18:33 ict kernel: fb: OSD2 as afbcd mode,afbc_type=2 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: create ion_client ffffffc0221e0000, handle=ffffffc0c51d0340 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: ion memory(2): created fb at 0x00000000ea500000, size 1 MiB Sep 01 13:18:33 ict kernel: fb: 2, phy: 0x00000000ea500000, vir:0xffffff800f9b7000, size=1024K Sep 01 13:18:33 ict kernel: fb: Frame buffer memory assigned at Sep 01 13:18:33 ict kernel: fb: 2, phy: 0x00000000ea500000, vir:0xffffff800f9b7000, size=1024K Sep 01 13:18:33 ict kernel: fb: 2, phy: 0x00000000ea500000, vir:0xffffff800f9b7000, size=1024K Sep 01 13:18:33 ict kernel: fb: logo_index=0,fb_index=2 Sep 01 13:18:33 ict kernel: fb: ---------------clear fb2 memory ffffff800f9b7000 Sep 01 13:18:33 ict kernel: fb: osd[2] canvas.idx =0x41 Sep 01 13:18:33 ict kernel: fb: osd[2] canvas.addr=0xea500000 Sep 01 13:18:33 ict kernel: fb: osd[2] canvas.width=128 Sep 01 13:18:33 ict kernel: fb: osd[2] canvas.height=32 Sep 01 13:18:33 ict kernel: fb: osd[2] frame.width=32 Sep 01 13:18:33 ict kernel: fb: osd[2] frame.height=32 Sep 01 13:18:33 ict kernel: fb: osd[2] out_addr_id =0x3 Sep 01 13:18:33 ict systemd[1]: Started Raise network interfaces. Sep 01 13:18:33 ict systemd[1]: Reached target Network. Sep 01 13:18:33 ict systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped. Sep 01 13:18:33 ict systemd[1]: Starting Permit User Sessions... Sep 01 13:18:33 ict systemd[1]: Starting Network Time Service... Sep 01 13:18:33 ict systemd[1]: Starting Flexible IR remote input/output application support... Sep 01 13:18:33 ict systemd[1]: Reached target Network is Online. Sep 01 13:18:33 ict kernel: fb: vpu clkc clock is 199 MHZ Sep 01 13:18:33 ict kernel: vpu: switch_vpu_mem_pd: unsupport vpu mod: 18 Sep 01 13:18:33 ict kernel: vpu: switch_vpu_mem_pd: unsupport vpu mod: 22 Sep 01 13:18:33 ict kernel: vpu: switch_vpu_mem_pd: unsupport vpu mod: 53 Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, cma:ffffff800a8a1b30 Sep 01 13:18:33 ict kernel: fb: malloc_osd_memory, 1231, base:0x00000000cf400000, size:8388608 Sep 01 13:18:33 ict kernel: fb: use ion buffer for fb memory, fb_index=3 Sep 01 13:18:33 ict kernel: fb: OSD3 as afbcd mode,afbc_type=2 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: create ion_client ffffffc0221e0000, handle=ffffffc0c51d0480 Sep 01 13:18:33 ict kernel: meson-fb meson-fb: ion memory(3): created fb at 0x00000000ea600000, size 8 MiB Sep 01 13:18:33 ict kernel: fb: 3, phy: 0x00000000ea600000, vir:0xffffff800fad0000, size=8192K Sep 01 13:18:33 ict kernel: fb: Frame buffer memory assigned at Sep 01 13:18:33 ict kernel: fb: 3, phy: 0x00000000ea600000, vir:0xffffff800fad0000, size=8192K Sep 01 13:18:33 ict kernel: fb: 3, phy: 0x00000000ea600000, vir:0xffffff800fad0000, size=8192K Sep 01 13:18:33 ict kernel: fb: logo_index=0,fb_index=3 Sep 01 13:18:33 ict kernel: fb: ---------------clear fb3 memory ffffff800fad0000 Sep 01 13:18:33 ict kernel: fb: osd[3] canvas.idx =0x42 Sep 01 13:18:33 ict kernel: fb: osd[3] canvas.addr=0xea600000 Sep 01 13:18:33 ict kernel: fb: osd[3] canvas.width=128 Sep 01 13:18:33 ict kernel: fb: osd[3] canvas.height=32 Sep 01 13:18:33 ict kernel: fb: osd[3] frame.width=32 Sep 01 13:18:33 ict kernel: fb: osd[3] frame.height=32 Sep 01 13:18:33 ict kernel: fb: osd[3] out_addr_id =0x4 Sep 01 13:18:33 ict systemd[1]: Starting LSB: Brings up/down network automatically... Sep 01 13:18:33 ict systemd[1]: Starting /etc/rc.local Compatibility... Sep 01 13:18:33 ict systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:33 ict lircd-0.10.1[2427]: Info: lircd: Opening log, level: Info Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Version: lircd 0.10.1 Sep 01 13:18:33 ict systemd[1]: Starting Samba NMB Daemon... Sep 01 13:18:33 ict systemd[1]: Started Permit User Sessions. Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: System info: Linux ict 4.9.241+ #15 SMP PREEMPT Thu Feb 10 11:27:37 CET 2022 aarch64 GNU/Linux Sep 01 13:18:33 ict rc.local[2431]: Simple mixer control 'Audio hdmi-out mute',0 Sep 01 13:18:33 ict rc.local[2431]: Capabilities: pswitch pswitch-joined Sep 01 13:18:33 ict rc.local[2431]: Playback channels: Mono Sep 01 13:18:33 ict rc.local[2431]: Mono: Playback [off] Sep 01 13:18:33 ict systemd[1]: Started /etc/rc.local Compatibility. Sep 01 13:18:33 ict systemd[1]: Starting Hold until boot process finishes up... Sep 01 13:18:33 ict ntpd[2426]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 01 13:18:33 ict systemd[1]: Starting Terminate Plymouth Boot Screen... Sep 01 13:18:33 ict ntpd[2426]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 01 13:18:33 ict systemd[1]: Started Network Time Service. Sep 01 13:18:33 ict ntpd[2459]: proto: precision = 0.750 usec (-20) Sep 01 13:18:33 ict systemd[1]: iptables.service: Succeeded. Sep 01 13:18:33 ict systemd[1]: Received SIGRTMIN+21 from PID 1961 (plymouthd). Sep 01 13:18:33 ict ntpd[2459]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 01 13:18:33 ict ntpd[2459]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 01 13:18:33 ict ntpd[2459]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 979 days ago Sep 01 13:18:33 ict ntpd[2459]: Listen and drop on 0 v6wildcard [::]:123 Sep 01 13:18:33 ict ntpd[2459]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 01 13:18:33 ict ntpd[2459]: Listen normally on 2 lo 127.0.0.1:123 Sep 01 13:18:33 ict ntpd[2459]: Listening on routing socket on fd #19 for interface updates Sep 01 13:18:33 ict ntpd[2459]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 13:18:33 ict ntpd[2459]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 01 13:18:33 ict lircd-0.10.1[2427]: Info: Initial device: auto Sep 01 13:18:33 ict lircd-0.10.1[2427]: Info: Initial device: auto Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: driver: devinput Sep 01 13:18:33 ict lircd[2427]: lircd-0.10.1[2427]: Info: lircd: Opening log, level: Info Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: output: /var/run/lirc/lircd Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: nodaemon: 1 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: logfile: syslog Sep 01 13:18:33 ict lircd[2427]: lircd-0.10.1[2427]: Notice: Using systemd fd Sep 01 13:18:33 ict lircd[2427]: lircd-0.10.1[2427]: Warning: Running as root Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: immediate-init: 0 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: permission: 666 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: driver-options: Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: listen: 0 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: connect: (null) Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: userelease: 0 Sep 01 13:18:33 ict lircd[2427]: lircd-0.10.1[2427]: Info: Using remote: odroid. Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: effective_user: (null) Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: release_suffix: _EVUP Sep 01 13:18:33 ict systemd[1]: Started Flexible IR remote input/output application support. Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: allow_simulate: 0 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: repeat_max: 600 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: configfile: /etc/lirc/lircd.conf Sep 01 13:18:33 ict lircd[2427]: lircd-0.10.1[2427]: Notice: lircd(devinput) ready, using /var/run/lirc/lircd Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Options: dynamic_codes: (null) Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Current driver: devinput Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Driver API version: 4 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Driver version: 0.10.0 Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/devinput.html Sep 01 13:18:33 ict lircd-0.10.1[2427]: Info: lircd: Opening log, level: Info Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: Using systemd fd Sep 01 13:18:33 ict lircd-0.10.1[2427]: Warning: Running as root Sep 01 13:18:33 ict systemd[1]: Received SIGRTMIN+21 from PID 1961 (plymouthd). Sep 01 13:18:33 ict lircd-0.10.1[2427]: Info: Using remote: odroid. Sep 01 13:18:33 ict systemd[1]: plymouth-quit.service: Succeeded. Sep 01 13:18:33 ict lircd-0.10.1[2427]: Notice: lircd(devinput) ready, using /var/run/lirc/lircd Sep 01 13:18:33 ict systemd[1]: Started Terminate Plymouth Boot Screen. Sep 01 13:18:33 ict systemd[1]: plymouth-quit-wait.service: Succeeded. Sep 01 13:18:33 ict kernel: fb: osd_release now.index=3,open_count=1 Sep 01 13:18:33 ict kernel: fb: osd_release now.index=2,open_count=1 Sep 01 13:18:33 ict kernel: fb: osd_release now.index=1,open_count=1 Sep 01 13:18:33 ict systemd[1]: Started Hold until boot process finishes up. Sep 01 13:18:33 ict ifplugd(eth0)[2477]: ifplugd 0.28 initializing. Sep 01 13:18:33 ict ifplugd(eth0)[2477]: Using interface eth0/00:1E:06:4A:58:79 with driver (version: Jan_2016) Sep 01 13:18:33 ict ifplugd(eth0)[2477]: Using detection mode: SIOCETHTOOL Sep 01 13:18:33 ict ifplugd(eth0)[2477]: Initialization complete, link beat not detected. Sep 01 13:18:33 ict systemd[1]: Started Getty on tty1. Sep 01 13:18:33 ict systemd[1]: Started Serial Getty on ttyS0. Sep 01 13:18:33 ict systemd[1]: Reached target Login Prompts. Sep 01 13:18:33 ict ifplugd[2428]: Network Interface Plugging Daemon...start eth0...done. Sep 01 13:18:33 ict systemd[1]: Started LSB: Brings up/down network automatically. Sep 01 13:18:33 ict haveged[2229]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.3.0 CTV); collect: 128K Sep 01 13:18:33 ict haveged[2229]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 12/40; sz: 15012/57848 Sep 01 13:18:33 ict haveged[2229]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.9983 Sep 01 13:18:33 ict haveged[2229]: haveged: fills: 0, generated: 0 Sep 01 13:18:33 ict loadcpufreq[2254]: Loading cpufreq kernel modules...done (none). Sep 01 13:18:33 ict systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling. Sep 01 13:18:33 ict systemd[1]: Starting LSB: set CPUFreq kernel parameters... Sep 01 13:18:33 ict cpufrequtils[2510]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done. Sep 01 13:18:33 ict systemd[1]: Started LSB: set CPUFreq kernel parameters. Sep 01 13:18:34 ict nmbd[2447]: [2025/09/01 13:18:34.047100, 0] ../source3/nmbd/asyncdns.c:158(start_async_dns) Sep 01 13:18:34 ict nmbd[2447]: started asyncdns process 2522 Sep 01 13:18:34 ict nmbd[2447]: [2025/09/01 13:18:34.049112, 0] ../lib/util/become_daemon.c:149(daemon_status) Sep 01 13:18:34 ict nmbd[2447]: daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ... Sep 01 13:18:34 ict nmbd[2447]: [2025/09/01 13:18:34.049285, 0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets) Sep 01 13:18:34 ict nmbd[2447]: NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6). Sep 01 13:18:34 ict wireless.js[2239]: WIRELESS: No wireless interface, exiting Sep 01 13:18:34 ict iw[2527]: command failed: No such device (-19) Sep 01 13:18:34 ict iwconfig[2530]: Error for wireless request "Set Power Management" (8B2C) : Sep 01 13:18:34 ict iwconfig[2530]: SET failed on device wlan0 ; No such device. Sep 01 13:18:34 ict systemd[1]: wireless.service: Succeeded. Sep 01 13:18:34 ict systemd[1]: Started Wireless Services. Sep 01 13:18:34 ict systemd[1]: Started Volumio Backend Module. Sep 01 13:18:34 ict systemd[1]: Started Volumio Cpu Tweaker. Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: Setting RT Priority for mpd Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: chrt: cannot obtain the list of tasks: No such file or directory Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: Setting MPD Affinity Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: pid 3's current affinity mask: 1 Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Sep 01 13:18:34 ict volumio-cpu-tweak[2534]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Sep 01 13:18:34 ict systemd[1]: volumio_cpu_tweak.service: Succeeded. Sep 01 13:18:34 ict ntpd[2459]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 01 13:18:35 ict ntpd[2459]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 01 13:18:36 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:36 ict volumio[2533]: info: ----- Volumio3 ---- Sep 01 13:18:36 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:36 ict volumio[2533]: info: ----- System startup ---- Sep 01 13:18:36 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:36 ict dhcpcd[2307]: eth0: carrier acquired Sep 01 13:18:36 ict kernel: meson6-dwmac ff3f0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Sep 01 13:18:36 ict dhcpcd[2307]: DUID 00:01:00:01:2d:f7:8e:5d:00:1e:06:4a:58:79 Sep 01 13:18:36 ict dhcpcd[2307]: eth0: IAID 06:4a:58:79 Sep 01 13:18:36 ict dhcpcd[2307]: eth0: adding address fe80::21e:6ff:fe4a:5879 Sep 01 13:18:36 ict dhcpcd[2307]: ipv6_addaddr1: Permission denied Sep 01 13:18:36 ict dhcpcd[2307]: eth0: probing address 192.168.144.36/24 Sep 01 13:18:36 ict ntpd[2459]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 01 13:18:36 ict ifplugd(eth0)[2477]: Link beat detected. Sep 01 13:18:36 ict ifplugd(eth0)[2477]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Sep 01 13:18:36 ict ifplugd(eth0)[2477]: client: ifup: interface eth0 already configured Sep 01 13:18:37 ict ifplugd(eth0)[2477]: Program executed successfully. Sep 01 13:18:37 ict volumio[2533]: info: MYVOLUMIO Environment detected Sep 01 13:18:37 ict volumio[2533]: info: Plugin folders cleanup Sep 01 13:18:37 ict volumio[2533]: info: Scanning into folder /volumio/app/plugins/ Sep 01 13:18:37 ict volumio[2533]: info: Scanning category audio_interface Sep 01 13:18:37 ict volumio[2533]: info: Scanning category miscellanea Sep 01 13:18:37 ict volumio[2533]: info: Scanning category music_service Sep 01 13:18:37 ict volumio[2533]: info: Scanning category plugins.json Sep 01 13:18:37 ict volumio[2533]: info: Scanning category system_controller Sep 01 13:18:37 ict volumio[2533]: info: Scanning category user_interface Sep 01 13:18:37 ict volumio[2533]: info: Scanning into folder /data/plugins/ Sep 01 13:18:37 ict volumio[2533]: info: Scanning category audio_interface Sep 01 13:18:37 ict volumio[2533]: info: Scanning category music_service Sep 01 13:18:37 ict volumio[2533]: info: Plugin folders cleanup completed Sep 01 13:18:37 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:37 ict volumio[2533]: info: ----- Core plugins startup ---- Sep 01 13:18:37 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:37 ict volumio[2533]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 13:18:37 ict volumio[2533]: info: Adding plugin upnp to MyMusic Plugins Sep 01 13:18:37 ict volumio[2533]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 13:18:37 ict volumio[2533]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 13:18:37 ict volumio[2533]: info: Loading plugins from folder /data/plugins/ Sep 01 13:18:37 ict volumio[2533]: info: Loading plugin "system"... Sep 01 13:18:37 ict volumio[2533]: info: Loading plugin "appearance"... Sep 01 13:18:37 ict dhcpcd[2307]: eth0: soliciting an IPv6 router Sep 01 13:18:37 ict ntpd[2459]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 01 13:18:37 ict volumio-remote-updater[2242]: [2025-09-01 13:18:37] [connect] Successful connection Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "network"... Sep 01 13:18:38 ict volumio[2533]: info: Refreshing Cached IP Addresses Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "services"... Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "alsa_controller"... Sep 01 13:18:38 ict sudo[2572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 13:18:38 ict sudo[2574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 13:18:38 ict sudo[2570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 13:18:38 ict sudo[2570]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:38 ict sudo[2572]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:38 ict sudo[2574]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:38 ict sudo[2570]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:38 ict sudo[2574]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:38 ict sudo[2572]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:38 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "wizard"... Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "networkfs"... Sep 01 13:18:38 ict volumio[2533]: info: Starting Udev Watcher for removable devices Sep 01 13:18:38 ict volumio[2533]: info: Ignoring mount for partition: boot Sep 01 13:18:38 ict volumio[2533]: info: Ignoring mount for partition: volumio Sep 01 13:18:38 ict volumio[2533]: info: Ignoring mount for partition: volumio_data Sep 01 13:18:38 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "volumio_command_line_client"... Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "upnp"... Sep 01 13:18:38 ict volumio[2533]: info: [1756725518567] Starting Upmpd Daemon Sep 01 13:18:38 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "my_music"... Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "mpd"... Sep 01 13:18:38 ict volumio[2533]: info: Loading plugin "upnp_browser"... Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "alarm-clock"... Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "airplay_emulation"... Sep 01 13:18:39 ict volumio[2533]: info: Starting Shairport Sync Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "last_100"... Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "webradio"... Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "i2s_dacs"... Sep 01 13:18:39 ict volumio[2533]: info: I2S DAC not set, start Auto-detection Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "volumiodiscovery"... Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** For more information see Sep 01 13:18:39 ict node[2533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 13:18:39 ict volumio[2533]: *** WARNING *** For more information see Sep 01 13:18:39 ict node[2533]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 13:18:39 ict node[2533]: *** WARNING *** For more information see Sep 01 13:18:39 ict node[2533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 13:18:39 ict node[2533]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 13:18:39 ict node[2533]: *** WARNING *** For more information see Sep 01 13:18:39 ict volumio[2533]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 13:18:39 ict volumio[2533]: info: Discovery: Started advertising with name: ICT Sep 01 13:18:39 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 13:18:39 ict volumio[2533]: info: Loading plugin "soundcloud"... Sep 01 13:18:40 ict volumio[2533]: info: Loading plugin "spop"... Sep 01 13:18:41 ict dhcpcd[2307]: eth0: using static address 192.168.144.36/24 Sep 01 13:18:41 ict dhcpcd[2307]: eth0: adding route to 192.168.144.0/24 Sep 01 13:18:41 ict avahi-daemon[2245]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.144.36. Sep 01 13:18:41 ict dhcpcd[2307]: eth0: adding default route via 192.168.144.1 Sep 01 13:18:41 ict avahi-daemon[2245]: New relevant interface eth0.IPv4 for mDNS. Sep 01 13:18:41 ict avahi-daemon[2245]: Registering new address record for 192.168.144.36 on eth0.IPv4. Sep 01 13:18:41 ict volumio[2533]: info: Loading plugin "youtube2"... Sep 01 13:18:42 ict ntpd[2459]: Listen normally on 3 eth0 192.168.144.36:123 Sep 01 13:18:42 ict ntpd[2459]: new interface(s) found: waking up resolver Sep 01 13:18:44 ict nmbd[2447]: [2025/09/01 13:18:44.055773, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 13:18:44 ict systemd[1]: Started Samba NMB Daemon. Sep 01 13:18:44 ict nmbd[2447]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Sep 01 13:18:44 ict systemd[1]: Starting Samba Winbind Daemon... Sep 01 13:18:44 ict winbindd[2604]: [2025/09/01 13:18:44.328738, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Sep 01 13:18:44 ict winbindd[2604]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Sep 01 13:18:44 ict winbindd[2604]: [2025/09/01 13:18:44.343180, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 13:18:44 ict winbindd[2604]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Sep 01 13:18:44 ict systemd[1]: Started Samba Winbind Daemon. Sep 01 13:18:44 ict systemd[1]: Starting Samba SMB Daemon... Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "outputs"... Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "albumart"... Sep 01 13:18:44 ict volumio[2533]: info: Plugin example_plugin is not enabled Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "inputs"... Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "updater_comm"... Sep 01 13:18:44 ict volumio[2533]: info: Plugin mpdemulation is not enabled Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "rest_api"... Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "websocket"... Sep 01 13:18:44 ict volumio[2533]: info: Starting Socket.io Server version 2.3.0 Sep 01 13:18:44 ict volumio[2533]: info: Loading plugin "fusiondsp"... Sep 01 13:18:44 ict volumio[2533]: Forking 3 albumart workers Sep 01 13:18:45 ict smbd[2616]: [2025/09/01 13:18:45.161174, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 01 13:18:45 ict systemd[1]: Started Samba SMB Daemon. Sep 01 13:18:45 ict smbd[2616]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Sep 01 13:18:45 ict systemd[1]: Reached target Multi-User System. Sep 01 13:18:45 ict systemd[1]: Reached target Graphical Interface. Sep 01 13:18:45 ict systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 01 13:18:45 ict systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 01 13:18:45 ict systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 01 13:18:45 ict systemd[1]: Startup finished in 10.366s (kernel) + 14.832s (userspace) = 25.199s. Sep 01 13:18:45 ict volumio[2533]: info: Applying required configuration parameters for plugin fusiondsp Sep 01 13:18:45 ict volumio[2533]: Starting albumart workers Sep 01 13:18:45 ict volumio[2533]: Starting albumart workers Sep 01 13:18:45 ict volumio[2533]: info: Loading i18n strings for locale en Sep 01 13:18:45 ict volumio[2533]: Updating browse sources language Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:45 ict volumio[2533]: Starting albumart workers Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::initPlayerControls Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:18:45 ict volumio[2533]: Express server listening on port 3000 Sep 01 13:18:45 ict volumio[2533]: [Metrics] WebUI: 10s 124.37ms Sep 01 13:18:45 ict volumio[2533]: info: CoreStateMachine::resetVolumioState Sep 01 13:18:45 ict volumio[2533]: info: CoreStateMachine::getcurrentVolume Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 13:18:45 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:45 ict volumio[2533]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Sep 01 13:18:45 ict volumio[2533]: info: Completed loading Core Plugins Sep 01 13:18:45 ict volumio[2533]: info: Preparing to generate the ALSA configuration file Sep 01 13:18:45 ict volumio[2533]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 01 13:18:45 ict volumio[2533]: wlan0 Interface doesn't support scanning. Sep 01 13:18:45 ict volumio[2533]: info: Cannot use regular scanning, forcing with ap-force Sep 01 13:18:45 ict sudo[2671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 01 13:18:45 ict sudo[2671]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:45 ict sudo[2671]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:45 ict volumio[2533]: command failed: No such device (-19) Sep 01 13:18:45 ict volumio[2533]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 01 13:18:45 ict volumio[2533]: command failed: No such device (-19) Sep 01 13:18:45 ict volumio[2533]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 01 13:18:45 ict volumio[2533]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Sep 01 13:18:45 ict volumio[2533]: info: Reading ALSA contributions from plugins. Sep 01 13:18:46 ict volumio[2533]: verbose: New Socket.io Connection to 192.168.144.36 from 192.168.144.9 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Edg/139.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Sep 01 13:18:46 ict volumio[2533]: verbose: New Socket.io Connection to 192.168.144.36 from 192.168.144.9 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Edg/139.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Sep 01 13:18:46 ict volumio[2533]: verbose: New Socket.io Connection to 192.168.144.36 from 192.168.144.9 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Edg/139.0.0.0 Engine version: 3 Transport: polling Total Clients: 3 Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::pushState Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioPushState Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::updateTrackBlock Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrackBlock Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 13:18:46 ict volumio[2533]: info: Reloading queue from file Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::setRepeat null single undefined Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::pushState Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioPushState Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::setRandom false Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::pushState Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioPushState Sep 01 13:18:46 ict volumio[2533]: info: CoreStateMachine::pushState Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioPushState Sep 01 13:18:46 ict volumio[2533]: info: Asound.conf file unchanged, so no further update is needed Sep 01 13:18:46 ict volumio[2533]: info: Output device has changed, restarting MPD Sep 01 13:18:46 ict sudo[2708]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 13:18:46 ict sudo[2708]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict volumio[2533]: info: Output device has changed, restarting Shairport Sync Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict sudo[2708]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict sudo[2711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 13:18:46 ict sudo[2711]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict systemd[1]: Listening on mpd.socket. Sep 01 13:18:46 ict systemd[1]: Starting Music Player Daemon... Sep 01 13:18:46 ict volumio[2533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 13:18:46 ict volumio[2533]: info: ___________ START PLUGINS ___________ Sep 01 13:18:46 ict volumio[2533]: info: ControllerMpd::onStart: Initializing MPD Sep 01 13:18:46 ict volumio[2533]: info: Creating MPD Configuration file Sep 01 13:18:46 ict sudo[2718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 13:18:46 ict sudo[2718]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:18:46 ict sudo[2718]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 13:18:46 ict volumio[2533]: info: [1756725526308] CoreMusicLibrary::Adding element Media Servers Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:46 ict sudo[2721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 13:18:46 ict sudo[2721]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict sudo[2716]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 13:18:46 ict sudo[2716]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict sudo[2716]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:46 ict systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Sep 01 13:18:46 ict systemd[1]: mpd.service: Succeeded. Sep 01 13:18:46 ict systemd[1]: Stopped Music Player Daemon. Sep 01 13:18:46 ict systemd[1]: Starting Music Player Daemon... Sep 01 13:18:46 ict volumio[2533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 13:18:46 ict volumio[2533]: info: [1756725526416] CoreMusicLibrary::Adding element Last_100 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 13:18:46 ict volumio[2533]: info: [1756725526419] CoreMusicLibrary::Adding element Webradio Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 13:18:46 ict volumio[2533]: info: Initializing BBC Radios Sep 01 13:18:46 ict sudo[2726]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 13:18:46 ict sudo[2726]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict sudo[2726]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Sep 01 13:18:46 ict sudo[2726]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 13:18:46 ict volumio[2533]: info: [1756725526499] CoreMusicLibrary::Adding element SoundCloud Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:46 ict volumio[2533]: Cannot find translation for source SoundCloud Sep 01 13:18:46 ict volumio[2533]: info: Creating Spotify config file Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 13:18:46 ict volumio[2533]: info: [1756725526528] CoreMusicLibrary::Adding element YouTube2 Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:46 ict volumio[2533]: Cannot find translation for source SoundCloud Sep 01 13:18:46 ict volumio[2533]: Cannot find translation for source YouTube2 Sep 01 13:18:46 ict volumio[2533]: info: Loading i18n strings for locale en Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: FusionDsp - mixtype--------------------- Software Sep 01 13:18:46 ict volumio[2533]: info: Volumio Calling Home Sep 01 13:18:46 ict volumio[2533]: info: Preparing to generate the ALSA configuration file Sep 01 13:18:46 ict volumio[2533]: info: Discovery: adding 235cccdb-0a1a-4aa5-994d-9f3faf5eea5b Sep 01 13:18:46 ict volumio[2533]: info: Discovery: Found device ICT Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:46 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:46 ict volumio[2533]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 01 13:18:46 ict volumio[2533]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Sep 01 13:18:46 ict volumio[2533]: info: Reading ALSA contributions from plugins. Sep 01 13:18:46 ict volumio[2533]: info: MPD Permissions set Sep 01 13:18:46 ict volumio[2533]: info: MPD Permissions set Sep 01 13:18:46 ict volumio[2533]: info: Spotify config file written Sep 01 13:18:46 ict volumio[2533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 01 13:18:46 ict sudo[2746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 13:18:46 ict sudo[2746]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:46 ict volumio[2533]: info: Volumio called home Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict systemd[1]: Started go-librespot Daemon. Sep 01 13:18:46 ict sudo[2746]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:46 ict go-librespot[2752]: go-librespot daemon starting... Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 13:18:46 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:46 ict volumio[2533]: info: No need to fix Spotify hosts Sep 01 13:18:46 ict volumio[2533]: info: Starting Shairport Sync Sep 01 13:18:47 ict volumio[2533]: info: Starting Shairport Sync Sep 01 13:18:47 ict sudo[2769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 13:18:47 ict sudo[2769]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict volumio[2533]: info: Starting Shairport Sync Sep 01 13:18:47 ict sudo[2772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 13:18:47 ict sudo[2772]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Succeeded. Sep 01 13:18:47 ict systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=info msg="running go-librespot 0.3.2" Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=debug msg="app state loaded" Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=debug msg="stored credentials not found" Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 13:18:47 ict sudo[2769]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict sudo[2775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 13:18:47 ict sudo[2775]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:47 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Succeeded. Sep 01 13:18:47 ict systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict sudo[2772]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Succeeded. Sep 01 13:18:47 ict systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict sudo[2775]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict volumio[2533]: info: Shairport-Sync Started Sep 01 13:18:47 ict volumio[2533]: Error adding Membership: Error: addMembership EINVAL Sep 01 13:18:47 ict volumio[2533]: info: Asound.conf file unchanged, so no further update is needed Sep 01 13:18:47 ict volumio[2533]: info: Output device has changed, restarting MPD Sep 01 13:18:47 ict sudo[2782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 13:18:47 ict sudo[2782]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict volumio[2533]: info: Output device has changed, restarting Shairport Sync Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:47 ict sudo[2782]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict sudo[2786]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 13:18:47 ict sudo[2786]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict volumio[2533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 13:18:47 ict volumio[2533]: info: Shairport-Sync Started Sep 01 13:18:47 ict volumio[2533]: info: Shairport-Sync Started Sep 01 13:18:47 ict systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 01 13:18:47 ict systemd[1]: mpd.service: Succeeded. Sep 01 13:18:47 ict systemd[1]: Stopped Music Player Daemon. Sep 01 13:18:47 ict systemd[1]: Starting Music Player Daemon... Sep 01 13:18:47 ict volumio[2533]: info: MPD Permissions set Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 01 13:18:47 ict go-librespot[2752]: time="2025-09-01T13:18:47+02:00" level=info msg="zeroconf server listening on port 39313" Sep 01 13:18:47 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:47 ict volumio[2533]: info: Starting Shairport Sync Sep 01 13:18:47 ict sudo[2792]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 13:18:47 ict sudo[2792]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict sudo[2792]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Sep 01 13:18:47 ict sudo[2792]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict sudo[2801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 13:18:47 ict sudo[2801]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:47 ict systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 01 13:18:47 ict systemd[1]: shairport-sync.service: Succeeded. Sep 01 13:18:47 ict systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 01 13:18:47 ict sudo[2801]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:47 ict volumio[2533]: info: Shairport-Sync Started Sep 01 13:18:48 ict volumio[2533]: info: camilladsp spawned new process with pid 2814, instance 1, run: true Sep 01 13:18:48 ict volumio[2533]: info: camilladsp service started and running in background, instance 1 Sep 01 13:18:48 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 <-AAAAAAAAAAAAA Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp loaded Sep 01 13:18:48 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 13:18:48 ict sudo[2824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Sep 01 13:18:48 ict sudo[2824]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp - Reporting Fusion DSP Enabled Sep 01 13:18:48 ict volumio[2533]: info: Adding Signal Path Element [object Object] Sep 01 13:18:48 ict volumio[2533]: info: Adding fusiondspeq DSP Signal Path Element Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp - ---- installed callbackRead Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 01 13:18:48 ict systemd[1]: Started FusionDsp Daemon. Sep 01 13:18:48 ict sudo[2824]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict sudo[2829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 13:18:48 ict sudo[2829]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:48 ict volumio[2533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Sep 01 13:18:48 ict sudo[2829]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict sudo[2833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 13:18:48 ict sudo[2833]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:48 ict sudo[2833]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict volumio[2533]: info: FusionDsp - {"Reload":{"result":"Ok"}} Sep 01 13:18:48 ict mpd[2805]: Sep 01 13:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 13:18:48 ict sudo[2838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 13:18:48 ict sudo[2838]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 01 13:18:48 ict systemd[1]: Started Music Player Daemon. Sep 01 13:18:48 ict sudo[2711]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict sudo[2786]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict sudo[2721]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict systemd[1]: Started UPnP Renderer front-end to MPD. Sep 01 13:18:48 ict sudo[2838]: pam_unix(sudo:session): session closed for user root Sep 01 13:18:48 ict volumio[2533]: info: Completed starting Core Plugins Sep 01 13:18:48 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:48 ict volumio[2533]: info: ----- MyVolumio plugins startup ---- Sep 01 13:18:48 ict volumio[2533]: info: ------------------------------------------- Sep 01 13:18:48 ict volumio[2533]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 13:18:49 ict volumio[2533]: error: MPD error: The expression evaluated to a falsy value: Sep 01 13:18:49 ict volumio[2533]: assert.ok(self.idling) Sep 01 13:18:49 ict volumio[2533]: error: The expression evaluated to a falsy value: Sep 01 13:18:49 ict volumio[2533]: assert.ok(self.idling) Sep 01 13:18:49 ict volumio[2533]: error: MPD error: The expression evaluated to a falsy value: Sep 01 13:18:49 ict volumio[2533]: assert.ok(self.idling) Sep 01 13:18:49 ict volumio[2533]: error: The expression evaluated to a falsy value: Sep 01 13:18:49 ict volumio[2533]: assert.ok(self.idling) Sep 01 13:18:49 ict volumio[2533]: info: Upmpdcli Daemon Started Sep 01 13:18:49 ict volumio[2533]: info: MPD running with PID2805 Sep 01 13:18:49 ict volumio[2533]: ,establishing connection Sep 01 13:18:49 ict volumio[2533]: error: updateQueue error: null Sep 01 13:18:49 ict volumio[2533]: error: updateQueue error: null Sep 01 13:18:49 ict volumio[2842]: Generating RSA private key, 4096 bit long modulus (2 primes) Sep 01 13:18:49 ict volumio[2533]: info: go-librespot daemon successfully initialized Sep 01 13:18:50 ict volumio-remote-updater[2242]: [2025-09-01 13:18:50] [connect] Successful connection Sep 01 13:18:50 ict volumio-remote-updater[2242]: [2025-09-01 13:18:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756725530 101 Sep 01 13:18:50 ict volumio[2533]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 6 Sep 01 13:18:51 ict volumio[2533]: verbose: New Socket.io Connection to 192.168.144.36 from 192.168.144.9 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Edg/139.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:51 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:51 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 13:18:51 ict volumio[2533]: info: Received Get System Info Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 13:18:51 ict volumio[2533]: info: Discovery: Getting this device information Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:51 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:51 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:51 ict volumio[2533]: info: Listing playlists Sep 01 13:18:51 ict volumio[2842]: .................................................++++ Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 13:18:51 ict volumio[2533]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 13:18:51 ict volumio[2842]: ..........++++ Sep 01 13:18:51 ict volumio[2842]: e is 65537 (0x010001) Sep 01 13:18:51 ict volumio[2842]: writing RSA key Sep 01 13:18:52 ict volumio[2533]: info: Initializing connection to go-librespot Websocket Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="new websocket client" Sep 01 13:18:53 ict volumio[2533]: info: Connection to go-librespot Websocket established Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="obtained new client token: AAB3cONAyvE3LHPMG5VCyNiptsPt3HFKpM0sWYzUYEdmM62oR2g1O9wyHx0vmCSe4wP3UaXgK06w0H3pzMfw3oKVZe0kt45VpflN3GocX+TKfyUmE2rqsBSZc0KpXUNfgJvhKG4X3v57YXjzsptPFrv9gTiAON1YV4bfk63X332iuZaBDCKuuh1iArIqWv5jfxBKMc1G7nfcz3CLg97NWEOXkqyoXQIxbzTBphajnZHW5liP1EHTTxw+" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="completed keyexchange" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="completed challenge" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=info msg="authenticated AP" username="xp*********************ef" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=info msg="authenticated Login5" username="xp*********************ef" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=info msg="accepted zeroconf from Beheer-Yorick.lh-techniek.local" username="xp*********************ef" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="dealer connection opened" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=trace msg="starting accesspoint recv loop" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=trace msg="starting dealer recv loop" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=trace msg="received accesspoint ping" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="received connection id: OTAyYzBjZDYtNTA3...M0MyNDIzNDdENg==" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=trace msg="received accesspoint pong ack" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="put connect state because NEW_DEVICE" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="handling transfer player command from 4e34ee4615b9e7f65caf7c3acdef9470f0b21255" Sep 01 13:18:53 ict volumio[2533]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="resolved context of track" uri="spotify:user:xpsxiz9yes6ra7oms8ivpfwef:collection" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=trace msg="fetched new page 0 with 206 items (list: 206)" uri="spotify:user:xpsxiz9yes6ra7oms8ivpfwef:collection" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="shuffled context with seed 3066445718961843306 (len: 206, keep: 121)" uri="spotify:user:xpsxiz9yes6ra7oms8ivpfwef:collection" Sep 01 13:18:53 ict go-librespot[2752]: time="2025-09-01T13:18:53+02:00" level=debug msg="loading track (paused: true, position: 34456ms)" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="emitting websocket event: will_play" Sep 01 13:18:54 ict volumio[2533]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2PnlsTsOTLE5jnBnNe2K0A","play_origin":"android-auto"}} Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=warning msg="original track has no formats, alternatives have a total of 8" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="selected format OGG_VORBIS_320 (a79aa9faca728e33dcbb23f0b59a2a65728bf540)" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="requested aes key for file a79aa9faca728e33dcbb23f0b59a2a65728bf540, gid: 2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1686" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched first chunk of 14, total size is 7271870 bytes" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="seek to 34456ms (diff: 230ms, samples: 1519509, bytes: 1234554)" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="created new output device" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=info msg="loaded track \"The Emptiness Machine\" (paused: true, position: 34456ms, duration: 190427ms, prefetched: false)" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched chunk 5/13, size: 524288" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1285" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:2PnlsTsOTLE5jnBnNe2K0A" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="emitting websocket event: metadata" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="emitting websocket event: active" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="sending successful reply for dealer request" Sep 01 13:18:54 ict volumio[2533]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2PnlsTsOTLE5jnBnNe2K0A","name":"The Emptiness Machine","artist_names":["Linkin Park"],"album_name":"The Emptiness Machine","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c0db065619ed208515412917","position":34456,"duration":190427,"release_date":"year:2024 month:9 day:5","track_number":1,"disc_number":1}} Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 01 13:18:54 ict volumio[2533]: SPOTIFY: received: {"type":"active","data":null} Sep 01 13:18:54 ict volumio[2533]: info: Aligning Spotify Volume to Volumio Volume Sep 01 13:18:54 ict volumio[2533]: info: CoreCommandRouter::volumioGetState Sep 01 13:18:54 ict volumio[2533]: info: CorePlayQueue::getTrack 0 Sep 01 13:18:54 ict volumio[2533]: info: Setting Spotify Volume from Volumio: 100 Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 13:18:54 ict go-librespot[2752]: time="2025-09-01T13:18:54+02:00" level=trace msg="emitting websocket event: paused" Sep 01 13:18:54 ict volumio[2533]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2PnlsTsOTLE5jnBnNe2K0A","play_origin":"android-auto"}} Sep 01 13:18:54 ict volumio[2533]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 13:18:54 ict volumio[2533]: TypeError: Cannot read property 'service' of undefined Sep 01 13:18:54 ict volumio[2533]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Sep 01 13:18:54 ict volumio[2533]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Sep 01 13:18:54 ict volumio[2533]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Sep 01 13:18:54 ict volumio[2533]: at WebSocket.emit (events.js:400:28) Sep 01 13:18:54 ict volumio[2533]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Sep 01 13:18:54 ict volumio[2533]: at Receiver.emit (events.js:400:28) Sep 01 13:18:54 ict volumio[2533]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Sep 01 13:18:54 ict volumio[2533]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Sep 01 13:18:54 ict volumio[2533]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Sep 01 13:18:54 ict volumio[2533]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Sep 01 13:18:54 ict volumio[2533]: at writeOrBuffer (internal/streams/writable.js:358:12) Sep 01 13:18:54 ict volumio[2533]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Sep 01 13:18:54 ict volumio[2533]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Sep 01 13:18:54 ict volumio[2533]: at Socket.emit (events.js:400:28) Sep 01 13:18:54 ict volumio[2533]: at addChunk (internal/streams/readable.js:293:12) Sep 01 13:18:54 ict volumio[2533]: at readableAddChunk (internal/streams/readable.js:267:9) Sep 01 13:18:54 ict volumio[2533]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 13:18:54 ict sudo[2887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-01 13:17 Sep 01 13:18:54 ict sudo[2887]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="6e682b9410d28f3874f90b2d7789db824a859264" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7c81f20187867c3bd55475ead0f12800fe93082c" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 08 Jun 2024 11:49:15 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="odroidc4" VOLUMIO_DEVICENAME="Odroid-C4" VOLUMIO_HASH="d2400f5f761721872d49eaefed0badd6"