Oct 8 19:51:16.931806 kernel: Booting Linux on physical CPU 0x0000000000 [0x413fd0c1] Oct 8 19:51:16.931827 kernel: Linux version 6.6.54-flatcar (build@pony-truck.infra.kinvolk.io) (aarch64-cros-linux-gnu-gcc (Gentoo Hardened 13.3.1_p20240614 p17) 13.3.1 20240614, GNU ld (Gentoo 2.42 p3) 2.42.0) #1 SMP PREEMPT Tue Oct 8 18:25:39 -00 2024 Oct 8 19:51:16.931837 kernel: KASLR enabled Oct 8 19:51:16.931843 kernel: efi: EFI v2.7 by EDK II Oct 8 19:51:16.931849 kernel: efi: SMBIOS 3.0=0xdced0000 MEMATTR=0xdba86018 ACPI 2.0=0xd9710018 RNG=0xd971e498 MEMRESERVE=0xd9b43d18 Oct 8 19:51:16.931854 kernel: random: crng init done Oct 8 19:51:16.931862 kernel: ACPI: Early table checksum verification disabled Oct 8 19:51:16.931868 kernel: ACPI: RSDP 0x00000000D9710018 000024 (v02 BOCHS ) Oct 8 19:51:16.931874 kernel: ACPI: XSDT 0x00000000D971FE98 000064 (v01 BOCHS BXPC 00000001 01000013) Oct 8 19:51:16.931882 kernel: ACPI: FACP 0x00000000D971FA98 000114 (v06 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931888 kernel: ACPI: DSDT 0x00000000D9717518 0014A2 (v02 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931893 kernel: ACPI: APIC 0x00000000D971FC18 0001A8 (v04 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931899 kernel: ACPI: PPTT 0x00000000D971D898 00009C (v02 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931905 kernel: ACPI: GTDT 0x00000000D971E818 000060 (v02 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931913 kernel: ACPI: MCFG 0x00000000D971E918 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931920 kernel: ACPI: SPCR 0x00000000D971FF98 000050 (v02 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931927 kernel: ACPI: DBG2 0x00000000D971E418 000057 (v00 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931933 kernel: ACPI: IORT 0x00000000D971E718 000080 (v03 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:51:16.931939 kernel: ACPI: SPCR: console: pl011,mmio,0x9000000,9600 Oct 8 19:51:16.931945 kernel: NUMA: Failed to initialise from firmware Oct 8 19:51:16.931952 kernel: NUMA: Faking a node at [mem 0x0000000040000000-0x00000000dcffffff] Oct 8 19:51:16.931958 kernel: NUMA: NODE_DATA [mem 0xdc958800-0xdc95dfff] Oct 8 19:51:16.931978 kernel: Zone ranges: Oct 8 19:51:16.931984 kernel: DMA [mem 0x0000000040000000-0x00000000dcffffff] Oct 8 19:51:16.931991 kernel: DMA32 empty Oct 8 19:51:16.931999 kernel: Normal empty Oct 8 19:51:16.932006 kernel: Movable zone start for each node Oct 8 19:51:16.932012 kernel: Early memory node ranges Oct 8 19:51:16.932018 kernel: node 0: [mem 0x0000000040000000-0x00000000d976ffff] Oct 8 19:51:16.932025 kernel: node 0: [mem 0x00000000d9770000-0x00000000d9b3ffff] Oct 8 19:51:16.932031 kernel: node 0: [mem 0x00000000d9b40000-0x00000000dce1ffff] Oct 8 19:51:16.932038 kernel: node 0: [mem 0x00000000dce20000-0x00000000dceaffff] Oct 8 19:51:16.932044 kernel: node 0: [mem 0x00000000dceb0000-0x00000000dcebffff] Oct 8 19:51:16.932051 kernel: node 0: [mem 0x00000000dcec0000-0x00000000dcfdffff] Oct 8 19:51:16.932105 kernel: node 0: [mem 0x00000000dcfe0000-0x00000000dcffffff] Oct 8 19:51:16.932112 kernel: Initmem setup node 0 [mem 0x0000000040000000-0x00000000dcffffff] Oct 8 19:51:16.932123 kernel: On node 0, zone DMA: 12288 pages in unavailable ranges Oct 8 19:51:16.932134 kernel: psci: probing for conduit method from ACPI. Oct 8 19:51:16.932141 kernel: psci: PSCIv1.1 detected in firmware. Oct 8 19:51:16.932148 kernel: psci: Using standard PSCI v0.2 function IDs Oct 8 19:51:16.932157 kernel: psci: Trusted OS migration not required Oct 8 19:51:16.932164 kernel: psci: SMC Calling Convention v1.1 Oct 8 19:51:16.932171 kernel: smccc: KVM: hypervisor services detected (0x00000000 0x00000000 0x00000000 0x00000003) Oct 8 19:51:16.932179 kernel: percpu: Embedded 31 pages/cpu s86632 r8192 d32152 u126976 Oct 8 19:51:16.932187 kernel: pcpu-alloc: s86632 r8192 d32152 u126976 alloc=31*4096 Oct 8 19:51:16.932193 kernel: pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 Oct 8 19:51:16.932200 kernel: Detected PIPT I-cache on CPU0 Oct 8 19:51:16.932207 kernel: CPU features: detected: GIC system register CPU interface Oct 8 19:51:16.932214 kernel: CPU features: detected: Hardware dirty bit management Oct 8 19:51:16.932221 kernel: CPU features: detected: Spectre-v4 Oct 8 19:51:16.932228 kernel: CPU features: detected: Spectre-BHB Oct 8 19:51:16.932234 kernel: CPU features: kernel page table isolation forced ON by KASLR Oct 8 19:51:16.932242 kernel: CPU features: detected: Kernel page table isolation (KPTI) Oct 8 19:51:16.932250 kernel: CPU features: detected: ARM erratum 1418040 Oct 8 19:51:16.932257 kernel: CPU features: detected: SSBS not fully self-synchronizing Oct 8 19:51:16.932263 kernel: alternatives: applying boot alternatives Oct 8 19:51:16.932271 kernel: Kernel command line: BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200 flatcar.first_boot=detected acpi=force verity.usrhash=f7968382bc5b46f9b6104a9f012cfba991c8ea306771e716a099618547de81d3 Oct 8 19:51:16.932278 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. Oct 8 19:51:16.932285 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Oct 8 19:51:16.932292 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Oct 8 19:51:16.932299 kernel: Fallback order for Node 0: 0 Oct 8 19:51:16.932306 kernel: Built 1 zonelists, mobility grouping on. Total pages: 633024 Oct 8 19:51:16.932312 kernel: Policy zone: DMA Oct 8 19:51:16.932319 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Oct 8 19:51:16.932327 kernel: software IO TLB: area num 4. Oct 8 19:51:16.932334 kernel: software IO TLB: mapped [mem 0x00000000d2e00000-0x00000000d6e00000] (64MB) Oct 8 19:51:16.932341 kernel: Memory: 2386468K/2572288K available (10304K kernel code, 2184K rwdata, 8092K rodata, 39360K init, 897K bss, 185820K reserved, 0K cma-reserved) Oct 8 19:51:16.932348 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Oct 8 19:51:16.932355 kernel: trace event string verifier disabled Oct 8 19:51:16.932362 kernel: rcu: Preemptible hierarchical RCU implementation. Oct 8 19:51:16.932370 kernel: rcu: RCU event tracing is enabled. Oct 8 19:51:16.932376 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Oct 8 19:51:16.932383 kernel: Trampoline variant of Tasks RCU enabled. Oct 8 19:51:16.932390 kernel: Tracing variant of Tasks RCU enabled. Oct 8 19:51:16.932397 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Oct 8 19:51:16.932404 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Oct 8 19:51:16.932412 kernel: NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 Oct 8 19:51:16.932419 kernel: GICv3: 256 SPIs implemented Oct 8 19:51:16.932425 kernel: GICv3: 0 Extended SPIs implemented Oct 8 19:51:16.932432 kernel: Root IRQ handler: gic_handle_irq Oct 8 19:51:16.932439 kernel: GICv3: GICv3 features: 16 PPIs, DirectLPI Oct 8 19:51:16.932445 kernel: GICv3: CPU0: found redistributor 0 region 0:0x00000000080a0000 Oct 8 19:51:16.932452 kernel: ITS [mem 0x08080000-0x0809ffff] Oct 8 19:51:16.932459 kernel: ITS@0x0000000008080000: allocated 8192 Devices @400d0000 (indirect, esz 8, psz 64K, shr 1) Oct 8 19:51:16.932466 kernel: ITS@0x0000000008080000: allocated 8192 Interrupt Collections @400e0000 (flat, esz 8, psz 64K, shr 1) Oct 8 19:51:16.932473 kernel: GICv3: using LPI property table @0x00000000400f0000 Oct 8 19:51:16.932479 kernel: GICv3: CPU0: using allocated LPI pending table @0x0000000040100000 Oct 8 19:51:16.932487 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Oct 8 19:51:16.932494 kernel: arch_timer: Enabling local workaround for ARM erratum 1418040 Oct 8 19:51:16.932501 kernel: arch_timer: cp15 timer(s) running at 25.00MHz (virt). Oct 8 19:51:16.932508 kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x5c40939b5, max_idle_ns: 440795202646 ns Oct 8 19:51:16.932514 kernel: sched_clock: 56 bits at 25MHz, resolution 40ns, wraps every 4398046511100ns Oct 8 19:51:16.932521 kernel: arm-pv: using stolen time PV Oct 8 19:51:16.932528 kernel: Console: colour dummy device 80x25 Oct 8 19:51:16.932535 kernel: ACPI: Core revision 20230628 Oct 8 19:51:16.932542 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 50.00 BogoMIPS (lpj=25000) Oct 8 19:51:16.932550 kernel: pid_max: default: 32768 minimum: 301 Oct 8 19:51:16.932558 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,integrity Oct 8 19:51:16.932566 kernel: landlock: Up and running. Oct 8 19:51:16.932573 kernel: SELinux: Initializing. Oct 8 19:51:16.932580 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 8 19:51:16.932587 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 8 19:51:16.932594 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. Oct 8 19:51:16.932602 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. Oct 8 19:51:16.932610 kernel: rcu: Hierarchical SRCU implementation. Oct 8 19:51:16.932617 kernel: rcu: Max phase no-delay instances is 400. Oct 8 19:51:16.932625 kernel: Platform MSI: ITS@0x8080000 domain created Oct 8 19:51:16.932633 kernel: PCI/MSI: ITS@0x8080000 domain created Oct 8 19:51:16.932641 kernel: Remapping and enabling EFI services. Oct 8 19:51:16.932648 kernel: smp: Bringing up secondary CPUs ... Oct 8 19:51:16.932655 kernel: Detected PIPT I-cache on CPU1 Oct 8 19:51:16.932662 kernel: GICv3: CPU1: found redistributor 1 region 0:0x00000000080c0000 Oct 8 19:51:16.932669 kernel: GICv3: CPU1: using allocated LPI pending table @0x0000000040110000 Oct 8 19:51:16.932676 kernel: arch_timer: Enabling local workaround for ARM erratum 1418040 Oct 8 19:51:16.932683 kernel: CPU1: Booted secondary processor 0x0000000001 [0x413fd0c1] Oct 8 19:51:16.932690 kernel: Detected PIPT I-cache on CPU2 Oct 8 19:51:16.932699 kernel: GICv3: CPU2: found redistributor 2 region 0:0x00000000080e0000 Oct 8 19:51:16.932706 kernel: GICv3: CPU2: using allocated LPI pending table @0x0000000040120000 Oct 8 19:51:16.932718 kernel: arch_timer: Enabling local workaround for ARM erratum 1418040 Oct 8 19:51:16.932727 kernel: CPU2: Booted secondary processor 0x0000000002 [0x413fd0c1] Oct 8 19:51:16.932735 kernel: Detected PIPT I-cache on CPU3 Oct 8 19:51:16.932742 kernel: GICv3: CPU3: found redistributor 3 region 0:0x0000000008100000 Oct 8 19:51:16.932750 kernel: GICv3: CPU3: using allocated LPI pending table @0x0000000040130000 Oct 8 19:51:16.932757 kernel: arch_timer: Enabling local workaround for ARM erratum 1418040 Oct 8 19:51:16.932764 kernel: CPU3: Booted secondary processor 0x0000000003 [0x413fd0c1] Oct 8 19:51:16.932773 kernel: smp: Brought up 1 node, 4 CPUs Oct 8 19:51:16.932780 kernel: SMP: Total of 4 processors activated. Oct 8 19:51:16.932788 kernel: CPU features: detected: 32-bit EL0 Support Oct 8 19:51:16.932795 kernel: CPU features: detected: Data cache clean to the PoU not required for I/D coherence Oct 8 19:51:16.932802 kernel: CPU features: detected: Common not Private translations Oct 8 19:51:16.932810 kernel: CPU features: detected: CRC32 instructions Oct 8 19:51:16.932817 kernel: CPU features: detected: Enhanced Virtualization Traps Oct 8 19:51:16.932824 kernel: CPU features: detected: RCpc load-acquire (LDAPR) Oct 8 19:51:16.932833 kernel: CPU features: detected: LSE atomic instructions Oct 8 19:51:16.932840 kernel: CPU features: detected: Privileged Access Never Oct 8 19:51:16.932847 kernel: CPU features: detected: RAS Extension Support Oct 8 19:51:16.932854 kernel: CPU features: detected: Speculative Store Bypassing Safe (SSBS) Oct 8 19:51:16.932862 kernel: CPU: All CPU(s) started at EL1 Oct 8 19:51:16.932869 kernel: alternatives: applying system-wide alternatives Oct 8 19:51:16.932876 kernel: devtmpfs: initialized Oct 8 19:51:16.932883 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Oct 8 19:51:16.932891 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Oct 8 19:51:16.932899 kernel: pinctrl core: initialized pinctrl subsystem Oct 8 19:51:16.932906 kernel: SMBIOS 3.0.0 present. Oct 8 19:51:16.932914 kernel: DMI: QEMU KVM Virtual Machine, BIOS edk2-20230524-3.fc38 05/24/2023 Oct 8 19:51:16.932921 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Oct 8 19:51:16.932928 kernel: DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations Oct 8 19:51:16.932935 kernel: DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations Oct 8 19:51:16.932943 kernel: DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations Oct 8 19:51:16.932950 kernel: audit: initializing netlink subsys (disabled) Oct 8 19:51:16.932957 kernel: audit: type=2000 audit(0.025:1): state=initialized audit_enabled=0 res=1 Oct 8 19:51:16.933036 kernel: thermal_sys: Registered thermal governor 'step_wise' Oct 8 19:51:16.933044 kernel: cpuidle: using governor menu Oct 8 19:51:16.933052 kernel: hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. Oct 8 19:51:16.933059 kernel: ASID allocator initialised with 32768 entries Oct 8 19:51:16.933066 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Oct 8 19:51:16.933074 kernel: Serial: AMBA PL011 UART driver Oct 8 19:51:16.933081 kernel: Modules: 2G module region forced by RANDOMIZE_MODULE_REGION_FULL Oct 8 19:51:16.933089 kernel: Modules: 0 pages in range for non-PLT usage Oct 8 19:51:16.933096 kernel: Modules: 509024 pages in range for PLT usage Oct 8 19:51:16.933105 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Oct 8 19:51:16.933113 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page Oct 8 19:51:16.933125 kernel: HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages Oct 8 19:51:16.933133 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page Oct 8 19:51:16.933140 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Oct 8 19:51:16.933147 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page Oct 8 19:51:16.933155 kernel: HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages Oct 8 19:51:16.933162 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page Oct 8 19:51:16.933169 kernel: ACPI: Added _OSI(Module Device) Oct 8 19:51:16.933178 kernel: ACPI: Added _OSI(Processor Device) Oct 8 19:51:16.933185 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) Oct 8 19:51:16.933193 kernel: ACPI: Added _OSI(Processor Aggregator Device) Oct 8 19:51:16.933201 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Oct 8 19:51:16.933208 kernel: ACPI: Interpreter enabled Oct 8 19:51:16.933215 kernel: ACPI: Using GIC for interrupt routing Oct 8 19:51:16.933223 kernel: ACPI: MCFG table detected, 1 entries Oct 8 19:51:16.933230 kernel: ARMH0011:00: ttyAMA0 at MMIO 0x9000000 (irq = 12, base_baud = 0) is a SBSA Oct 8 19:51:16.933238 kernel: printk: console [ttyAMA0] enabled Oct 8 19:51:16.933245 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Oct 8 19:51:16.933404 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Oct 8 19:51:16.933482 kernel: acpi PNP0A08:00: _OSC: platform does not support [LTR] Oct 8 19:51:16.933551 kernel: acpi PNP0A08:00: _OSC: OS now controls [PCIeHotplug PME AER PCIeCapability] Oct 8 19:51:16.933626 kernel: acpi PNP0A08:00: ECAM area [mem 0x4010000000-0x401fffffff] reserved by PNP0C02:00 Oct 8 19:51:16.933692 kernel: acpi PNP0A08:00: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff] Oct 8 19:51:16.933702 kernel: ACPI: Remapped I/O 0x000000003eff0000 to [io 0x0000-0xffff window] Oct 8 19:51:16.933713 kernel: PCI host bridge to bus 0000:00 Oct 8 19:51:16.933837 kernel: pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff window] Oct 8 19:51:16.933909 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0xffff window] Oct 8 19:51:16.934030 kernel: pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff window] Oct 8 19:51:16.934146 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Oct 8 19:51:16.934235 kernel: pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000 Oct 8 19:51:16.934328 kernel: pci 0000:00:01.0: [1af4:1005] type 00 class 0x00ff00 Oct 8 19:51:16.934405 kernel: pci 0000:00:01.0: reg 0x10: [io 0x0000-0x001f] Oct 8 19:51:16.934476 kernel: pci 0000:00:01.0: reg 0x14: [mem 0x10000000-0x10000fff] Oct 8 19:51:16.934546 kernel: pci 0000:00:01.0: reg 0x20: [mem 0x8000000000-0x8000003fff 64bit pref] Oct 8 19:51:16.934616 kernel: pci 0000:00:01.0: BAR 4: assigned [mem 0x8000000000-0x8000003fff 64bit pref] Oct 8 19:51:16.934687 kernel: pci 0000:00:01.0: BAR 1: assigned [mem 0x10000000-0x10000fff] Oct 8 19:51:16.934758 kernel: pci 0000:00:01.0: BAR 0: assigned [io 0x1000-0x101f] Oct 8 19:51:16.934821 kernel: pci_bus 0000:00: resource 4 [mem 0x10000000-0x3efeffff window] Oct 8 19:51:16.934892 kernel: pci_bus 0000:00: resource 5 [io 0x0000-0xffff window] Oct 8 19:51:16.934956 kernel: pci_bus 0000:00: resource 6 [mem 0x8000000000-0xffffffffff window] Oct 8 19:51:16.934977 kernel: ACPI: PCI: Interrupt link GSI0 configured for IRQ 35 Oct 8 19:51:16.934985 kernel: ACPI: PCI: Interrupt link GSI1 configured for IRQ 36 Oct 8 19:51:16.934993 kernel: ACPI: PCI: Interrupt link GSI2 configured for IRQ 37 Oct 8 19:51:16.935001 kernel: ACPI: PCI: Interrupt link GSI3 configured for IRQ 38 Oct 8 19:51:16.935008 kernel: iommu: Default domain type: Translated Oct 8 19:51:16.935016 kernel: iommu: DMA domain TLB invalidation policy: strict mode Oct 8 19:51:16.935026 kernel: efivars: Registered efivars operations Oct 8 19:51:16.935034 kernel: vgaarb: loaded Oct 8 19:51:16.935041 kernel: clocksource: Switched to clocksource arch_sys_counter Oct 8 19:51:16.935049 kernel: VFS: Disk quotas dquot_6.6.0 Oct 8 19:51:16.935057 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Oct 8 19:51:16.935064 kernel: pnp: PnP ACPI init Oct 8 19:51:16.935158 kernel: system 00:00: [mem 0x4010000000-0x401fffffff window] could not be reserved Oct 8 19:51:16.935170 kernel: pnp: PnP ACPI: found 1 devices Oct 8 19:51:16.935180 kernel: NET: Registered PF_INET protocol family Oct 8 19:51:16.935188 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Oct 8 19:51:16.935196 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Oct 8 19:51:16.935204 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Oct 8 19:51:16.935211 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Oct 8 19:51:16.935219 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Oct 8 19:51:16.935228 kernel: TCP: Hash tables configured (established 32768 bind 32768) Oct 8 19:51:16.935235 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 8 19:51:16.935243 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 8 19:51:16.935253 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Oct 8 19:51:16.935260 kernel: PCI: CLS 0 bytes, default 64 Oct 8 19:51:16.935268 kernel: kvm [1]: HYP mode not available Oct 8 19:51:16.935275 kernel: Initialise system trusted keyrings Oct 8 19:51:16.935283 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Oct 8 19:51:16.935291 kernel: Key type asymmetric registered Oct 8 19:51:16.935298 kernel: Asymmetric key parser 'x509' registered Oct 8 19:51:16.935306 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) Oct 8 19:51:16.935314 kernel: io scheduler mq-deadline registered Oct 8 19:51:16.935323 kernel: io scheduler kyber registered Oct 8 19:51:16.935330 kernel: io scheduler bfq registered Oct 8 19:51:16.935338 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input0 Oct 8 19:51:16.935346 kernel: ACPI: button: Power Button [PWRB] Oct 8 19:51:16.935354 kernel: ACPI: \_SB_.PCI0.GSI1: Enabled at IRQ 36 Oct 8 19:51:16.935427 kernel: virtio-pci 0000:00:01.0: enabling device (0005 -> 0007) Oct 8 19:51:16.935438 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Oct 8 19:51:16.935446 kernel: thunder_xcv, ver 1.0 Oct 8 19:51:16.935454 kernel: thunder_bgx, ver 1.0 Oct 8 19:51:16.935464 kernel: nicpf, ver 1.0 Oct 8 19:51:16.935472 kernel: nicvf, ver 1.0 Oct 8 19:51:16.935551 kernel: rtc-efi rtc-efi.0: registered as rtc0 Oct 8 19:51:16.935618 kernel: rtc-efi rtc-efi.0: setting system clock to 2024-10-08T19:51:16 UTC (1728417076) Oct 8 19:51:16.935628 kernel: hid: raw HID events driver (C) Jiri Kosina Oct 8 19:51:16.935636 kernel: hw perfevents: enabled with armv8_pmuv3_0 PMU driver, 7 counters available Oct 8 19:51:16.935644 kernel: watchdog: Delayed init of the lockup detector failed: -19 Oct 8 19:51:16.935651 kernel: watchdog: Hard watchdog permanently disabled Oct 8 19:51:16.935661 kernel: NET: Registered PF_INET6 protocol family Oct 8 19:51:16.935669 kernel: Segment Routing with IPv6 Oct 8 19:51:16.935677 kernel: In-situ OAM (IOAM) with IPv6 Oct 8 19:51:16.935685 kernel: NET: Registered PF_PACKET protocol family Oct 8 19:51:16.935692 kernel: Key type dns_resolver registered Oct 8 19:51:16.935700 kernel: registered taskstats version 1 Oct 8 19:51:16.935707 kernel: Loading compiled-in X.509 certificates Oct 8 19:51:16.935717 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.6.54-flatcar: e9e638352c282bfddf5aec6da700ad8191939d05' Oct 8 19:51:16.935727 kernel: Key type .fscrypt registered Oct 8 19:51:16.935737 kernel: Key type fscrypt-provisioning registered Oct 8 19:51:16.935747 kernel: ima: No TPM chip found, activating TPM-bypass! Oct 8 19:51:16.935754 kernel: ima: Allocated hash algorithm: sha1 Oct 8 19:51:16.935762 kernel: ima: No architecture policies found Oct 8 19:51:16.935770 kernel: alg: No test for fips(ansi_cprng) (fips_ansi_cprng) Oct 8 19:51:16.935782 kernel: clk: Disabling unused clocks Oct 8 19:51:16.935793 kernel: Freeing unused kernel memory: 39360K Oct 8 19:51:16.935800 kernel: Run /init as init process Oct 8 19:51:16.935808 kernel: with arguments: Oct 8 19:51:16.935817 kernel: /init Oct 8 19:51:16.935824 kernel: with environment: Oct 8 19:51:16.935832 kernel: HOME=/ Oct 8 19:51:16.935839 kernel: TERM=linux Oct 8 19:51:16.935847 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a Oct 8 19:51:16.935857 systemd[1]: systemd 255 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified) Oct 8 19:51:16.935867 systemd[1]: Detected virtualization kvm. Oct 8 19:51:16.935875 systemd[1]: Detected architecture arm64. Oct 8 19:51:16.935885 systemd[1]: Running in initrd. Oct 8 19:51:16.935893 systemd[1]: No hostname configured, using default hostname. Oct 8 19:51:16.935901 systemd[1]: Hostname set to . Oct 8 19:51:16.935910 systemd[1]: Initializing machine ID from VM UUID. Oct 8 19:51:16.935918 systemd[1]: Queued start job for default target initrd.target. Oct 8 19:51:16.935926 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:51:16.935935 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:51:16.935944 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Oct 8 19:51:16.935954 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 8 19:51:16.935972 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Oct 8 19:51:16.935981 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Oct 8 19:51:16.935992 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... Oct 8 19:51:16.936000 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... Oct 8 19:51:16.936009 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:51:16.936018 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:51:16.936028 systemd[1]: Reached target paths.target - Path Units. Oct 8 19:51:16.936037 systemd[1]: Reached target slices.target - Slice Units. Oct 8 19:51:16.936045 systemd[1]: Reached target swap.target - Swaps. Oct 8 19:51:16.936053 systemd[1]: Reached target timers.target - Timer Units. Oct 8 19:51:16.936062 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Oct 8 19:51:16.936070 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 8 19:51:16.936079 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Oct 8 19:51:16.936087 systemd[1]: Listening on systemd-journald.socket - Journal Socket. Oct 8 19:51:16.936098 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:51:16.936106 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 8 19:51:16.936114 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:51:16.936128 systemd[1]: Reached target sockets.target - Socket Units. Oct 8 19:51:16.936137 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Oct 8 19:51:16.936145 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 8 19:51:16.936153 systemd[1]: Finished network-cleanup.service - Network Cleanup. Oct 8 19:51:16.936162 systemd[1]: Starting systemd-fsck-usr.service... Oct 8 19:51:16.936170 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 8 19:51:16.936180 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 8 19:51:16.936188 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:51:16.936197 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Oct 8 19:51:16.936205 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:51:16.936213 systemd[1]: Finished systemd-fsck-usr.service. Oct 8 19:51:16.936222 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 8 19:51:16.936252 systemd-journald[238]: Collecting audit messages is disabled. Oct 8 19:51:16.936272 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:51:16.936283 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:51:16.936291 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Oct 8 19:51:16.936300 systemd-journald[238]: Journal started Oct 8 19:51:16.936319 systemd-journald[238]: Runtime Journal (/run/log/journal/24ad66ae4b7249de893e02873134bb3d) is 5.9M, max 47.3M, 41.4M free. Oct 8 19:51:16.918147 systemd-modules-load[239]: Inserted module 'overlay' Oct 8 19:51:16.939718 systemd-modules-load[239]: Inserted module 'br_netfilter' Oct 8 19:51:16.941429 kernel: Bridge firewalling registered Oct 8 19:51:16.941451 systemd[1]: Started systemd-journald.service - Journal Service. Oct 8 19:51:16.942812 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 8 19:51:16.952103 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:51:16.954040 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 8 19:51:16.958367 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 8 19:51:16.961674 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 8 19:51:16.967834 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:51:16.971423 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:51:16.973808 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:51:16.975349 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:51:16.989157 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Oct 8 19:51:16.991556 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 8 19:51:17.005298 dracut-cmdline[281]: dracut-dracut-053 Oct 8 19:51:17.007837 dracut-cmdline[281]: Using kernel command line parameters: rd.driver.pre=btrfs BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200 flatcar.first_boot=detected acpi=force verity.usrhash=f7968382bc5b46f9b6104a9f012cfba991c8ea306771e716a099618547de81d3 Oct 8 19:51:17.027096 systemd-resolved[284]: Positive Trust Anchors: Oct 8 19:51:17.027117 systemd-resolved[284]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 8 19:51:17.027157 systemd-resolved[284]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 8 19:51:17.032052 systemd-resolved[284]: Defaulting to hostname 'linux'. Oct 8 19:51:17.033092 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 8 19:51:17.036929 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:51:17.078995 kernel: SCSI subsystem initialized Oct 8 19:51:17.083982 kernel: Loading iSCSI transport class v2.0-870. Oct 8 19:51:17.091988 kernel: iscsi: registered transport (tcp) Oct 8 19:51:17.106022 kernel: iscsi: registered transport (qla4xxx) Oct 8 19:51:17.106083 kernel: QLogic iSCSI HBA Driver Oct 8 19:51:17.150820 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Oct 8 19:51:17.163142 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Oct 8 19:51:17.181130 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Oct 8 19:51:17.181183 kernel: device-mapper: uevent: version 1.0.3 Oct 8 19:51:17.182231 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com Oct 8 19:51:17.229998 kernel: raid6: neonx8 gen() 15751 MB/s Oct 8 19:51:17.246985 kernel: raid6: neonx4 gen() 15663 MB/s Oct 8 19:51:17.263988 kernel: raid6: neonx2 gen() 13230 MB/s Oct 8 19:51:17.280990 kernel: raid6: neonx1 gen() 10494 MB/s Oct 8 19:51:17.297986 kernel: raid6: int64x8 gen() 6956 MB/s Oct 8 19:51:17.314983 kernel: raid6: int64x4 gen() 7353 MB/s Oct 8 19:51:17.331984 kernel: raid6: int64x2 gen() 6130 MB/s Oct 8 19:51:17.349199 kernel: raid6: int64x1 gen() 5046 MB/s Oct 8 19:51:17.349215 kernel: raid6: using algorithm neonx8 gen() 15751 MB/s Oct 8 19:51:17.367154 kernel: raid6: .... xor() 11922 MB/s, rmw enabled Oct 8 19:51:17.367169 kernel: raid6: using neon recovery algorithm Oct 8 19:51:17.373983 kernel: xor: measuring software checksum speed Oct 8 19:51:17.374002 kernel: 8regs : 19793 MB/sec Oct 8 19:51:17.375237 kernel: 32regs : 17719 MB/sec Oct 8 19:51:17.375250 kernel: arm64_neon : 26848 MB/sec Oct 8 19:51:17.375260 kernel: xor: using function: arm64_neon (26848 MB/sec) Oct 8 19:51:17.436990 kernel: Btrfs loaded, zoned=no, fsverity=no Oct 8 19:51:17.457975 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Oct 8 19:51:17.468161 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:51:17.481323 systemd-udevd[466]: Using default interface naming scheme 'v255'. Oct 8 19:51:17.484969 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:51:17.493164 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Oct 8 19:51:17.507066 dracut-pre-trigger[474]: rd.md=0: removing MD RAID activation Oct 8 19:51:17.541613 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Oct 8 19:51:17.559222 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 8 19:51:17.603781 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:51:17.614163 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Oct 8 19:51:17.626988 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Oct 8 19:51:17.628835 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Oct 8 19:51:17.631218 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:51:17.634293 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 8 19:51:17.643202 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Oct 8 19:51:17.654986 kernel: virtio_blk virtio1: 1/0/0 default/read/poll queues Oct 8 19:51:17.655062 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Oct 8 19:51:17.660359 kernel: virtio_blk virtio1: [vda] 19775488 512-byte logical blocks (10.1 GB/9.43 GiB) Oct 8 19:51:17.664404 kernel: GPT:Primary header thinks Alt. header is not at the end of the disk. Oct 8 19:51:17.664447 kernel: GPT:9289727 != 19775487 Oct 8 19:51:17.664461 kernel: GPT:Alternate GPT header not at the end of the disk. Oct 8 19:51:17.665574 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Oct 8 19:51:17.665708 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:51:17.675013 kernel: GPT:9289727 != 19775487 Oct 8 19:51:17.675071 systemd[1]: Stopping dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:51:17.679148 kernel: GPT: Use GNU Parted to correct GPT errors. Oct 8 19:51:17.679176 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:51:17.677660 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 8 19:51:17.677849 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:51:17.680367 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:51:17.692254 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:51:17.697906 kernel: BTRFS: device label OEM devid 1 transid 12 /dev/vda6 scanned by (udev-worker) (509) Oct 8 19:51:17.697932 kernel: BTRFS: device fsid ad786f33-c7c5-429e-95f9-4ea457bd3916 devid 1 transid 40 /dev/vda3 scanned by (udev-worker) (522) Oct 8 19:51:17.711221 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Oct 8 19:51:17.712826 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:51:17.719311 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Oct 8 19:51:17.724277 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 8 19:51:17.728577 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Oct 8 19:51:17.729836 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132. Oct 8 19:51:17.745160 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Oct 8 19:51:17.747243 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:51:17.751728 disk-uuid[555]: Primary Header is updated. Oct 8 19:51:17.751728 disk-uuid[555]: Secondary Entries is updated. Oct 8 19:51:17.751728 disk-uuid[555]: Secondary Header is updated. Oct 8 19:51:17.755366 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:51:17.770996 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:51:17.771094 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:51:18.770983 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:51:18.771864 disk-uuid[556]: The operation has completed successfully. Oct 8 19:51:18.792346 systemd[1]: disk-uuid.service: Deactivated successfully. Oct 8 19:51:18.792457 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Oct 8 19:51:18.812136 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... Oct 8 19:51:18.814894 sh[578]: Success Oct 8 19:51:18.827987 kernel: device-mapper: verity: sha256 using implementation "sha256-ce" Oct 8 19:51:18.858832 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. Oct 8 19:51:18.872473 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... Oct 8 19:51:18.874134 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. Oct 8 19:51:18.885319 kernel: BTRFS info (device dm-0): first mount of filesystem ad786f33-c7c5-429e-95f9-4ea457bd3916 Oct 8 19:51:18.885354 kernel: BTRFS info (device dm-0): using crc32c (crc32c-generic) checksum algorithm Oct 8 19:51:18.885365 kernel: BTRFS warning (device dm-0): 'nologreplay' is deprecated, use 'rescue=nologreplay' instead Oct 8 19:51:18.887181 kernel: BTRFS info (device dm-0): disabling log replay at mount time Oct 8 19:51:18.887198 kernel: BTRFS info (device dm-0): using free space tree Oct 8 19:51:18.891140 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. Oct 8 19:51:18.892558 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Oct 8 19:51:18.893368 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Oct 8 19:51:18.896339 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Oct 8 19:51:18.906781 kernel: BTRFS info (device vda6): first mount of filesystem cbd8a2bc-d0a3-4040-91fa-086f2a330687 Oct 8 19:51:18.906826 kernel: BTRFS info (device vda6): using crc32c (crc32c-generic) checksum algorithm Oct 8 19:51:18.906837 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:51:18.909995 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:51:18.919977 kernel: BTRFS info (device vda6): last unmount of filesystem cbd8a2bc-d0a3-4040-91fa-086f2a330687 Oct 8 19:51:18.920070 systemd[1]: mnt-oem.mount: Deactivated successfully. Oct 8 19:51:18.926844 systemd[1]: Finished ignition-setup.service - Ignition (setup). Oct 8 19:51:18.938179 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Oct 8 19:51:18.998392 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 8 19:51:19.011170 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 8 19:51:19.032026 systemd-networkd[770]: lo: Link UP Oct 8 19:51:19.032369 ignition[681]: Ignition 2.19.0 Oct 8 19:51:19.032035 systemd-networkd[770]: lo: Gained carrier Oct 8 19:51:19.032375 ignition[681]: Stage: fetch-offline Oct 8 19:51:19.032723 systemd-networkd[770]: Enumeration completed Oct 8 19:51:19.032408 ignition[681]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:19.033159 systemd-networkd[770]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:51:19.032416 ignition[681]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:19.033176 systemd-networkd[770]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 8 19:51:19.032567 ignition[681]: parsed url from cmdline: "" Oct 8 19:51:19.033348 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 8 19:51:19.032571 ignition[681]: no config URL provided Oct 8 19:51:19.035244 systemd-networkd[770]: eth0: Link UP Oct 8 19:51:19.032576 ignition[681]: reading system config file "/usr/lib/ignition/user.ign" Oct 8 19:51:19.035247 systemd-networkd[770]: eth0: Gained carrier Oct 8 19:51:19.032588 ignition[681]: no config at "/usr/lib/ignition/user.ign" Oct 8 19:51:19.035255 systemd-networkd[770]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:51:19.032610 ignition[681]: op(1): [started] loading QEMU firmware config module Oct 8 19:51:19.035305 systemd[1]: Reached target network.target - Network. Oct 8 19:51:19.032614 ignition[681]: op(1): executing: "modprobe" "qemu_fw_cfg" Oct 8 19:51:19.042338 ignition[681]: op(1): [finished] loading QEMU firmware config module Oct 8 19:51:19.058241 ignition[681]: parsing config with SHA512: 73a6ae02cfe770dc5c201326e239e82ff60f98189d37b5b32388a25141246d761508c00e09d78461a3e93b25c87e0cbce0b5981b405ef552c9b22619856d494e Oct 8 19:51:19.059032 systemd-networkd[770]: eth0: DHCPv4 address 10.0.0.103/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 8 19:51:19.061237 unknown[681]: fetched base config from "system" Oct 8 19:51:19.061248 unknown[681]: fetched user config from "qemu" Oct 8 19:51:19.061569 ignition[681]: fetch-offline: fetch-offline passed Oct 8 19:51:19.063408 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Oct 8 19:51:19.061637 ignition[681]: Ignition finished successfully Oct 8 19:51:19.065194 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Oct 8 19:51:19.077152 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Oct 8 19:51:19.088018 ignition[776]: Ignition 2.19.0 Oct 8 19:51:19.088030 ignition[776]: Stage: kargs Oct 8 19:51:19.088211 ignition[776]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:19.088221 ignition[776]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:19.088874 ignition[776]: kargs: kargs passed Oct 8 19:51:19.088917 ignition[776]: Ignition finished successfully Oct 8 19:51:19.093001 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Oct 8 19:51:19.102150 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Oct 8 19:51:19.111394 ignition[784]: Ignition 2.19.0 Oct 8 19:51:19.111404 ignition[784]: Stage: disks Oct 8 19:51:19.111568 ignition[784]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:19.114393 systemd[1]: Finished ignition-disks.service - Ignition (disks). Oct 8 19:51:19.111577 ignition[784]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:19.115655 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Oct 8 19:51:19.112315 ignition[784]: disks: disks passed Oct 8 19:51:19.117474 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Oct 8 19:51:19.112363 ignition[784]: Ignition finished successfully Oct 8 19:51:19.119593 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 8 19:51:19.121564 systemd[1]: Reached target sysinit.target - System Initialization. Oct 8 19:51:19.123149 systemd[1]: Reached target basic.target - Basic System. Oct 8 19:51:19.135149 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Oct 8 19:51:19.146148 systemd-fsck[794]: ROOT: clean, 14/553520 files, 52654/553472 blocks Oct 8 19:51:19.150521 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Oct 8 19:51:19.154499 systemd[1]: Mounting sysroot.mount - /sysroot... Oct 8 19:51:19.202982 kernel: EXT4-fs (vda9): mounted filesystem 833c86f3-93dd-4526-bb43-c7809dac8e51 r/w with ordered data mode. Quota mode: none. Oct 8 19:51:19.203233 systemd[1]: Mounted sysroot.mount - /sysroot. Oct 8 19:51:19.204540 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Oct 8 19:51:19.217064 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 8 19:51:19.218756 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Oct 8 19:51:19.219931 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Oct 8 19:51:19.220016 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Oct 8 19:51:19.227952 kernel: BTRFS: device label OEM devid 1 transid 13 /dev/vda6 scanned by mount (802) Oct 8 19:51:19.227990 kernel: BTRFS info (device vda6): first mount of filesystem cbd8a2bc-d0a3-4040-91fa-086f2a330687 Oct 8 19:51:19.220068 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Oct 8 19:51:19.232927 kernel: BTRFS info (device vda6): using crc32c (crc32c-generic) checksum algorithm Oct 8 19:51:19.232947 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:51:19.224530 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Oct 8 19:51:19.226536 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Oct 8 19:51:19.236980 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:51:19.238800 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 8 19:51:19.273179 initrd-setup-root[827]: cut: /sysroot/etc/passwd: No such file or directory Oct 8 19:51:19.277497 initrd-setup-root[834]: cut: /sysroot/etc/group: No such file or directory Oct 8 19:51:19.280566 initrd-setup-root[841]: cut: /sysroot/etc/shadow: No such file or directory Oct 8 19:51:19.283492 initrd-setup-root[848]: cut: /sysroot/etc/gshadow: No such file or directory Oct 8 19:51:19.357252 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Oct 8 19:51:19.367069 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Oct 8 19:51:19.369671 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Oct 8 19:51:19.374988 kernel: BTRFS info (device vda6): last unmount of filesystem cbd8a2bc-d0a3-4040-91fa-086f2a330687 Oct 8 19:51:19.393434 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Oct 8 19:51:19.396018 ignition[916]: INFO : Ignition 2.19.0 Oct 8 19:51:19.396018 ignition[916]: INFO : Stage: mount Oct 8 19:51:19.397633 ignition[916]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:19.397633 ignition[916]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:19.397633 ignition[916]: INFO : mount: mount passed Oct 8 19:51:19.397633 ignition[916]: INFO : Ignition finished successfully Oct 8 19:51:19.399364 systemd[1]: Finished ignition-mount.service - Ignition (mount). Oct 8 19:51:19.409101 systemd[1]: Starting ignition-files.service - Ignition (files)... Oct 8 19:51:19.884190 systemd[1]: sysroot-oem.mount: Deactivated successfully. Oct 8 19:51:19.897158 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 8 19:51:19.903700 kernel: BTRFS: device label OEM devid 1 transid 14 /dev/vda6 scanned by mount (929) Oct 8 19:51:19.903731 kernel: BTRFS info (device vda6): first mount of filesystem cbd8a2bc-d0a3-4040-91fa-086f2a330687 Oct 8 19:51:19.903743 kernel: BTRFS info (device vda6): using crc32c (crc32c-generic) checksum algorithm Oct 8 19:51:19.905388 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:51:19.907983 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:51:19.908633 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 8 19:51:19.931181 ignition[946]: INFO : Ignition 2.19.0 Oct 8 19:51:19.931181 ignition[946]: INFO : Stage: files Oct 8 19:51:19.933006 ignition[946]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:19.933006 ignition[946]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:19.933006 ignition[946]: DEBUG : files: compiled without relabeling support, skipping Oct 8 19:51:19.933006 ignition[946]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Oct 8 19:51:19.933006 ignition[946]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Oct 8 19:51:19.939730 ignition[946]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Oct 8 19:51:19.939730 ignition[946]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Oct 8 19:51:19.939730 ignition[946]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/home/core/install.sh" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/home/core/install.sh" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(4): [started] writing file "/sysroot/etc/flatcar/update.conf" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(4): [finished] writing file "/sysroot/etc/flatcar/update.conf" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(5): [started] writing link "/sysroot/etc/extensions/kubernetes.raw" -> "/opt/extensions/kubernetes/kubernetes-v1.29.2-arm64.raw" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(5): [finished] writing link "/sysroot/etc/extensions/kubernetes.raw" -> "/opt/extensions/kubernetes/kubernetes-v1.29.2-arm64.raw" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(6): [started] writing file "/sysroot/opt/extensions/kubernetes/kubernetes-v1.29.2-arm64.raw" Oct 8 19:51:19.939730 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(6): GET https://github.com/flatcar/sysext-bakery/releases/download/latest/kubernetes-v1.29.2-arm64.raw: attempt #1 Oct 8 19:51:19.936085 unknown[946]: wrote ssh authorized keys file for user: core Oct 8 19:51:20.201793 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(6): GET result: OK Oct 8 19:51:20.476694 ignition[946]: INFO : files: createFilesystemsFiles: createFiles: op(6): [finished] writing file "/sysroot/opt/extensions/kubernetes/kubernetes-v1.29.2-arm64.raw" Oct 8 19:51:20.476694 ignition[946]: INFO : files: op(7): [started] processing unit "coreos-metadata.service" Oct 8 19:51:20.481980 ignition[946]: INFO : files: op(7): op(8): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 8 19:51:20.481980 ignition[946]: INFO : files: op(7): op(8): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 8 19:51:20.481980 ignition[946]: INFO : files: op(7): [finished] processing unit "coreos-metadata.service" Oct 8 19:51:20.481980 ignition[946]: INFO : files: op(9): [started] setting preset to disabled for "coreos-metadata.service" Oct 8 19:51:20.500966 ignition[946]: INFO : files: op(9): op(a): [started] removing enablement symlink(s) for "coreos-metadata.service" Oct 8 19:51:20.504771 ignition[946]: INFO : files: op(9): op(a): [finished] removing enablement symlink(s) for "coreos-metadata.service" Oct 8 19:51:20.506411 ignition[946]: INFO : files: op(9): [finished] setting preset to disabled for "coreos-metadata.service" Oct 8 19:51:20.506411 ignition[946]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Oct 8 19:51:20.506411 ignition[946]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Oct 8 19:51:20.506411 ignition[946]: INFO : files: files passed Oct 8 19:51:20.506411 ignition[946]: INFO : Ignition finished successfully Oct 8 19:51:20.508508 systemd[1]: Finished ignition-files.service - Ignition (files). Oct 8 19:51:20.523098 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Oct 8 19:51:20.524953 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Oct 8 19:51:20.527641 systemd[1]: ignition-quench.service: Deactivated successfully. Oct 8 19:51:20.528784 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Oct 8 19:51:20.532743 initrd-setup-root-after-ignition[975]: grep: /sysroot/oem/oem-release: No such file or directory Oct 8 19:51:20.536345 initrd-setup-root-after-ignition[977]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:51:20.536345 initrd-setup-root-after-ignition[977]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:51:20.539519 initrd-setup-root-after-ignition[981]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:51:20.538341 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 8 19:51:20.541040 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Oct 8 19:51:20.547085 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Oct 8 19:51:20.566217 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Oct 8 19:51:20.566353 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Oct 8 19:51:20.569301 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Oct 8 19:51:20.571158 systemd[1]: Reached target initrd.target - Initrd Default Target. Oct 8 19:51:20.572948 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Oct 8 19:51:20.573699 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Oct 8 19:51:20.588901 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 8 19:51:20.603216 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Oct 8 19:51:20.611363 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:51:20.612950 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:51:20.615098 systemd[1]: Stopped target timers.target - Timer Units. Oct 8 19:51:20.616944 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Oct 8 19:51:20.617159 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 8 19:51:20.619976 systemd[1]: Stopped target initrd.target - Initrd Default Target. Oct 8 19:51:20.621079 systemd[1]: Stopped target basic.target - Basic System. Oct 8 19:51:20.623156 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Oct 8 19:51:20.625088 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Oct 8 19:51:20.627042 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Oct 8 19:51:20.629203 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Oct 8 19:51:20.631183 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Oct 8 19:51:20.633336 systemd[1]: Stopped target sysinit.target - System Initialization. Oct 8 19:51:20.635216 systemd[1]: Stopped target local-fs.target - Local File Systems. Oct 8 19:51:20.637325 systemd[1]: Stopped target swap.target - Swaps. Oct 8 19:51:20.638894 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Oct 8 19:51:20.639054 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Oct 8 19:51:20.641607 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:51:20.643698 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:51:20.645833 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Oct 8 19:51:20.649996 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:51:20.651290 systemd[1]: dracut-initqueue.service: Deactivated successfully. Oct 8 19:51:20.651420 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Oct 8 19:51:20.654360 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Oct 8 19:51:20.654486 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Oct 8 19:51:20.656575 systemd[1]: Stopped target paths.target - Path Units. Oct 8 19:51:20.658272 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Oct 8 19:51:20.664011 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:51:20.665390 systemd[1]: Stopped target slices.target - Slice Units. Oct 8 19:51:20.667657 systemd[1]: Stopped target sockets.target - Socket Units. Oct 8 19:51:20.669332 systemd[1]: iscsid.socket: Deactivated successfully. Oct 8 19:51:20.669430 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Oct 8 19:51:20.670957 systemd[1]: iscsiuio.socket: Deactivated successfully. Oct 8 19:51:20.671052 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 8 19:51:20.672631 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Oct 8 19:51:20.672746 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 8 19:51:20.674527 systemd[1]: ignition-files.service: Deactivated successfully. Oct 8 19:51:20.674631 systemd[1]: Stopped ignition-files.service - Ignition (files). Oct 8 19:51:20.690186 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Oct 8 19:51:20.691884 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Oct 8 19:51:20.692880 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Oct 8 19:51:20.693040 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:51:20.695083 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Oct 8 19:51:20.695204 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Oct 8 19:51:20.701415 ignition[1001]: INFO : Ignition 2.19.0 Oct 8 19:51:20.701415 ignition[1001]: INFO : Stage: umount Oct 8 19:51:20.704301 ignition[1001]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:51:20.704301 ignition[1001]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:51:20.704301 ignition[1001]: INFO : umount: umount passed Oct 8 19:51:20.704301 ignition[1001]: INFO : Ignition finished successfully Oct 8 19:51:20.702245 systemd[1]: initrd-cleanup.service: Deactivated successfully. Oct 8 19:51:20.702345 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Oct 8 19:51:20.703827 systemd[1]: ignition-mount.service: Deactivated successfully. Oct 8 19:51:20.703902 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Oct 8 19:51:20.705719 systemd[1]: Stopped target network.target - Network. Oct 8 19:51:20.707222 systemd[1]: ignition-disks.service: Deactivated successfully. Oct 8 19:51:20.707289 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Oct 8 19:51:20.709459 systemd[1]: ignition-kargs.service: Deactivated successfully. Oct 8 19:51:20.709505 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Oct 8 19:51:20.711094 systemd[1]: ignition-setup.service: Deactivated successfully. Oct 8 19:51:20.711151 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Oct 8 19:51:20.712813 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Oct 8 19:51:20.712862 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Oct 8 19:51:20.714884 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Oct 8 19:51:20.717403 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Oct 8 19:51:20.719797 systemd[1]: sysroot-boot.mount: Deactivated successfully. Oct 8 19:51:20.720336 systemd[1]: sysroot-boot.service: Deactivated successfully. Oct 8 19:51:20.720436 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Oct 8 19:51:20.722407 systemd[1]: initrd-setup-root.service: Deactivated successfully. Oct 8 19:51:20.722466 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Oct 8 19:51:20.725316 systemd-networkd[770]: eth0: DHCPv6 lease lost Oct 8 19:51:20.727278 systemd[1]: systemd-networkd.service: Deactivated successfully. Oct 8 19:51:20.727411 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Oct 8 19:51:20.730606 systemd[1]: systemd-resolved.service: Deactivated successfully. Oct 8 19:51:20.730715 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Oct 8 19:51:20.734211 systemd[1]: systemd-networkd.socket: Deactivated successfully. Oct 8 19:51:20.734253 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:51:20.747094 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Oct 8 19:51:20.748852 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Oct 8 19:51:20.748923 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 8 19:51:20.751090 systemd[1]: systemd-sysctl.service: Deactivated successfully. Oct 8 19:51:20.751152 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:51:20.753075 systemd[1]: systemd-modules-load.service: Deactivated successfully. Oct 8 19:51:20.753136 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Oct 8 19:51:20.755374 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Oct 8 19:51:20.755424 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:51:20.757716 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:51:20.768283 systemd[1]: network-cleanup.service: Deactivated successfully. Oct 8 19:51:20.768389 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Oct 8 19:51:20.778630 systemd[1]: systemd-udevd.service: Deactivated successfully. Oct 8 19:51:20.778799 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:51:20.781247 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Oct 8 19:51:20.781295 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Oct 8 19:51:20.783141 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Oct 8 19:51:20.783180 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:51:20.784980 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Oct 8 19:51:20.785031 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Oct 8 19:51:20.787858 systemd[1]: dracut-cmdline.service: Deactivated successfully. Oct 8 19:51:20.787908 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Oct 8 19:51:20.790892 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Oct 8 19:51:20.790942 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:51:20.802138 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Oct 8 19:51:20.803241 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Oct 8 19:51:20.803302 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:51:20.805560 systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. Oct 8 19:51:20.805604 systemd[1]: Stopped systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:51:20.807676 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Oct 8 19:51:20.807719 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:51:20.810094 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 8 19:51:20.810156 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:51:20.812419 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Oct 8 19:51:20.814262 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Oct 8 19:51:20.815852 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Oct 8 19:51:20.818285 systemd[1]: Starting initrd-switch-root.service - Switch Root... Oct 8 19:51:20.827267 systemd[1]: Switching root. Oct 8 19:51:20.853258 systemd-journald[238]: Journal stopped Oct 8 19:51:21.554866 systemd-journald[238]: Received SIGTERM from PID 1 (systemd). Oct 8 19:51:21.554925 kernel: SELinux: policy capability network_peer_controls=1 Oct 8 19:51:21.554937 kernel: SELinux: policy capability open_perms=1 Oct 8 19:51:21.554947 kernel: SELinux: policy capability extended_socket_class=1 Oct 8 19:51:21.555080 kernel: SELinux: policy capability always_check_network=0 Oct 8 19:51:21.555094 kernel: SELinux: policy capability cgroup_seclabel=1 Oct 8 19:51:21.555104 kernel: SELinux: policy capability nnp_nosuid_transition=1 Oct 8 19:51:21.555124 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Oct 8 19:51:21.555136 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Oct 8 19:51:21.555147 systemd[1]: Successfully loaded SELinux policy in 34.546ms. Oct 8 19:51:21.555172 kernel: audit: type=1403 audit(1728417080.983:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Oct 8 19:51:21.555183 systemd[1]: Relabeled /dev, /dev/shm, /run, /sys/fs/cgroup in 9.604ms. Oct 8 19:51:21.555196 systemd[1]: systemd 255 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified) Oct 8 19:51:21.555207 systemd[1]: Detected virtualization kvm. Oct 8 19:51:21.555218 systemd[1]: Detected architecture arm64. Oct 8 19:51:21.555228 systemd[1]: Detected first boot. Oct 8 19:51:21.555239 systemd[1]: Initializing machine ID from VM UUID. Oct 8 19:51:21.555252 zram_generator::config[1046]: No configuration found. Oct 8 19:51:21.555266 systemd[1]: Populated /etc with preset unit settings. Oct 8 19:51:21.555277 systemd[1]: initrd-switch-root.service: Deactivated successfully. Oct 8 19:51:21.555290 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Oct 8 19:51:21.555301 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Oct 8 19:51:21.555312 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Oct 8 19:51:21.555325 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Oct 8 19:51:21.555337 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Oct 8 19:51:21.555347 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Oct 8 19:51:21.555359 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Oct 8 19:51:21.555369 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Oct 8 19:51:21.555380 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Oct 8 19:51:21.555395 systemd[1]: Created slice user.slice - User and Session Slice. Oct 8 19:51:21.555406 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:51:21.555417 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:51:21.555430 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Oct 8 19:51:21.555440 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Oct 8 19:51:21.555451 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Oct 8 19:51:21.555462 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 8 19:51:21.555474 systemd[1]: Expecting device dev-ttyAMA0.device - /dev/ttyAMA0... Oct 8 19:51:21.555485 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:51:21.555501 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Oct 8 19:51:21.555511 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Oct 8 19:51:21.555522 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Oct 8 19:51:21.555534 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Oct 8 19:51:21.555546 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:51:21.555556 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 8 19:51:21.555567 systemd[1]: Reached target slices.target - Slice Units. Oct 8 19:51:21.555579 systemd[1]: Reached target swap.target - Swaps. Oct 8 19:51:21.555589 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Oct 8 19:51:21.555600 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Oct 8 19:51:21.555611 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:51:21.555624 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 8 19:51:21.555635 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:51:21.555645 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Oct 8 19:51:21.555656 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Oct 8 19:51:21.555667 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Oct 8 19:51:21.555677 systemd[1]: Mounting media.mount - External Media Directory... Oct 8 19:51:21.555688 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Oct 8 19:51:21.555699 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Oct 8 19:51:21.555710 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Oct 8 19:51:21.555723 systemd[1]: var-lib-machines.mount - Virtual Machine and Container Storage (Compatibility) was skipped because of an unmet condition check (ConditionPathExists=/var/lib/machines.raw). Oct 8 19:51:21.555734 systemd[1]: Reached target machines.target - Containers. Oct 8 19:51:21.555746 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Oct 8 19:51:21.555757 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:51:21.555767 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 8 19:51:21.555779 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Oct 8 19:51:21.555789 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:51:21.555800 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 8 19:51:21.555812 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:51:21.555823 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Oct 8 19:51:21.555834 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:51:21.555845 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Oct 8 19:51:21.555856 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Oct 8 19:51:21.555866 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Oct 8 19:51:21.555878 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Oct 8 19:51:21.555888 systemd[1]: Stopped systemd-fsck-usr.service. Oct 8 19:51:21.555898 kernel: fuse: init (API version 7.39) Oct 8 19:51:21.555910 kernel: loop: module loaded Oct 8 19:51:21.555920 kernel: ACPI: bus type drm_connector registered Oct 8 19:51:21.555930 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 8 19:51:21.555940 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 8 19:51:21.555951 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Oct 8 19:51:21.555972 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Oct 8 19:51:21.555984 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 8 19:51:21.555995 systemd[1]: verity-setup.service: Deactivated successfully. Oct 8 19:51:21.556006 systemd[1]: Stopped verity-setup.service. Oct 8 19:51:21.556037 systemd-journald[1114]: Collecting audit messages is disabled. Oct 8 19:51:21.556060 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Oct 8 19:51:21.556071 systemd-journald[1114]: Journal started Oct 8 19:51:21.556093 systemd-journald[1114]: Runtime Journal (/run/log/journal/24ad66ae4b7249de893e02873134bb3d) is 5.9M, max 47.3M, 41.4M free. Oct 8 19:51:21.556138 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Oct 8 19:51:21.343813 systemd[1]: Queued start job for default target multi-user.target. Oct 8 19:51:21.362415 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Oct 8 19:51:21.362775 systemd[1]: systemd-journald.service: Deactivated successfully. Oct 8 19:51:21.560526 systemd[1]: Started systemd-journald.service - Journal Service. Oct 8 19:51:21.561276 systemd[1]: Mounted media.mount - External Media Directory. Oct 8 19:51:21.562538 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Oct 8 19:51:21.563863 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Oct 8 19:51:21.565258 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Oct 8 19:51:21.568008 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Oct 8 19:51:21.569539 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:51:21.572344 systemd[1]: modprobe@configfs.service: Deactivated successfully. Oct 8 19:51:21.572498 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Oct 8 19:51:21.574208 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:51:21.574352 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:51:21.575802 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 8 19:51:21.575940 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 8 19:51:21.577521 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:51:21.577670 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:51:21.579202 systemd[1]: modprobe@fuse.service: Deactivated successfully. Oct 8 19:51:21.579331 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Oct 8 19:51:21.581411 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:51:21.581582 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:51:21.583042 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 8 19:51:21.584564 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Oct 8 19:51:21.586289 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Oct 8 19:51:21.599190 systemd[1]: Reached target network-pre.target - Preparation for Network. Oct 8 19:51:21.608086 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Oct 8 19:51:21.610258 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Oct 8 19:51:21.611449 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Oct 8 19:51:21.611499 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 8 19:51:21.613447 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management (Varlink). Oct 8 19:51:21.615793 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Oct 8 19:51:21.617872 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Oct 8 19:51:21.619063 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:51:21.620167 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Oct 8 19:51:21.622096 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Oct 8 19:51:21.623427 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 8 19:51:21.624702 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Oct 8 19:51:21.625825 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 8 19:51:21.630284 systemd-journald[1114]: Time spent on flushing to /var/log/journal/24ad66ae4b7249de893e02873134bb3d is 13.274ms for 838 entries. Oct 8 19:51:21.630284 systemd-journald[1114]: System Journal (/var/log/journal/24ad66ae4b7249de893e02873134bb3d) is 8.0M, max 195.6M, 187.6M free. Oct 8 19:51:21.647391 systemd-journald[1114]: Received client request to flush runtime journal. Oct 8 19:51:21.633142 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 8 19:51:21.635098 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Oct 8 19:51:21.640198 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 8 19:51:21.644546 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:51:21.646625 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Oct 8 19:51:21.648331 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Oct 8 19:51:21.654043 kernel: loop0: detected capacity change from 0 to 114328 Oct 8 19:51:21.651987 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Oct 8 19:51:21.653849 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Oct 8 19:51:21.655735 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Oct 8 19:51:21.660702 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Oct 8 19:51:21.669015 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Oct 8 19:51:21.673337 systemd-tmpfiles[1158]: ACLs are not supported, ignoring. Oct 8 19:51:21.673352 systemd-tmpfiles[1158]: ACLs are not supported, ignoring. Oct 8 19:51:21.677234 systemd[1]: Starting systemd-machine-id-commit.service - Commit a transient machine-id on disk... Oct 8 19:51:21.680200 systemd[1]: Starting systemd-udev-settle.service - Wait for udev To Complete Device Initialization... Oct 8 19:51:21.682570 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:51:21.684436 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:51:21.692451 systemd[1]: Starting systemd-sysusers.service - Create System Users... Oct 8 19:51:21.696740 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Oct 8 19:51:21.699060 systemd[1]: Finished systemd-machine-id-commit.service - Commit a transient machine-id on disk. Oct 8 19:51:21.700125 kernel: loop1: detected capacity change from 0 to 114432 Oct 8 19:51:21.702631 udevadm[1172]: systemd-udev-settle.service is deprecated. Please fix lvm2-activation-early.service, lvm2-activation.service not to pull it in. Oct 8 19:51:21.723353 systemd[1]: Finished systemd-sysusers.service - Create System Users. Oct 8 19:51:21.734003 kernel: loop2: detected capacity change from 0 to 194512 Oct 8 19:51:21.734134 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 8 19:51:21.746685 systemd-tmpfiles[1180]: ACLs are not supported, ignoring. Oct 8 19:51:21.746704 systemd-tmpfiles[1180]: ACLs are not supported, ignoring. Oct 8 19:51:21.750706 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:51:21.765026 kernel: loop3: detected capacity change from 0 to 114328 Oct 8 19:51:21.768985 kernel: loop4: detected capacity change from 0 to 114432 Oct 8 19:51:21.773982 kernel: loop5: detected capacity change from 0 to 194512 Oct 8 19:51:21.777557 (sd-merge)[1184]: Using extensions 'containerd-flatcar', 'docker-flatcar', 'kubernetes'. Oct 8 19:51:21.777946 (sd-merge)[1184]: Merged extensions into '/usr'. Oct 8 19:51:21.782794 systemd[1]: Reloading requested from client PID 1157 ('systemd-sysext') (unit systemd-sysext.service)... Oct 8 19:51:21.782819 systemd[1]: Reloading... Oct 8 19:51:21.839318 zram_generator::config[1209]: No configuration found. Oct 8 19:51:21.907649 ldconfig[1152]: /sbin/ldconfig: /lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Oct 8 19:51:21.931640 systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, updating /var/run/docker.sock → /run/docker.sock; please update the unit file accordingly. Oct 8 19:51:21.967347 systemd[1]: Reloading finished in 183 ms. Oct 8 19:51:21.996562 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Oct 8 19:51:21.998285 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Oct 8 19:51:22.013122 systemd[1]: Starting ensure-sysext.service... Oct 8 19:51:22.014944 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 8 19:51:22.025812 systemd[1]: Reloading requested from client PID 1244 ('systemctl') (unit ensure-sysext.service)... Oct 8 19:51:22.025827 systemd[1]: Reloading... Oct 8 19:51:22.035117 systemd-tmpfiles[1245]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Oct 8 19:51:22.035686 systemd-tmpfiles[1245]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Oct 8 19:51:22.036473 systemd-tmpfiles[1245]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Oct 8 19:51:22.036799 systemd-tmpfiles[1245]: ACLs are not supported, ignoring. Oct 8 19:51:22.036858 systemd-tmpfiles[1245]: ACLs are not supported, ignoring. Oct 8 19:51:22.039236 systemd-tmpfiles[1245]: Detected autofs mount point /boot during canonicalization of boot. Oct 8 19:51:22.039249 systemd-tmpfiles[1245]: Skipping /boot Oct 8 19:51:22.046413 systemd-tmpfiles[1245]: Detected autofs mount point /boot during canonicalization of boot. Oct 8 19:51:22.046429 systemd-tmpfiles[1245]: Skipping /boot Oct 8 19:51:22.074999 zram_generator::config[1272]: No configuration found. Oct 8 19:51:22.153943 systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, updating /var/run/docker.sock → /run/docker.sock; please update the unit file accordingly. Oct 8 19:51:22.190624 systemd[1]: Reloading finished in 164 ms. Oct 8 19:51:22.206229 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Oct 8 19:51:22.227420 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:51:22.235403 systemd[1]: Starting audit-rules.service - Load Security Auditing Rules... Oct 8 19:51:22.238384 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Oct 8 19:51:22.240768 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Oct 8 19:51:22.246254 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 8 19:51:22.250563 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:51:22.253825 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Oct 8 19:51:22.258493 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:51:22.260599 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:51:22.263958 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:51:22.266740 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:51:22.268392 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:51:22.272237 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Oct 8 19:51:22.276868 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:51:22.277024 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:51:22.278576 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:51:22.278721 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:51:22.280499 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:51:22.280629 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:51:22.290186 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 8 19:51:22.290365 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 8 19:51:22.292072 systemd-udevd[1315]: Using default interface naming scheme 'v255'. Oct 8 19:51:22.295002 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Oct 8 19:51:22.296929 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Oct 8 19:51:22.299588 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:51:22.315985 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:51:22.320272 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:51:22.322417 augenrules[1341]: No rules Oct 8 19:51:22.322728 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:51:22.324020 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:51:22.326322 systemd[1]: Starting systemd-update-done.service - Update is Completed... Oct 8 19:51:22.328063 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:51:22.330065 systemd[1]: Finished audit-rules.service - Load Security Auditing Rules. Oct 8 19:51:22.331845 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Oct 8 19:51:22.334346 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:51:22.334478 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:51:22.337500 systemd[1]: Started systemd-userdbd.service - User Database Manager. Oct 8 19:51:22.341404 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:51:22.341551 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:51:22.343307 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:51:22.343438 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:51:22.354381 systemd[1]: Finished systemd-update-done.service - Update is Completed. Oct 8 19:51:22.362120 systemd[1]: Finished ensure-sysext.service. Oct 8 19:51:22.368729 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:51:22.379249 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:51:22.382168 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 8 19:51:22.383986 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 40 scanned by (udev-worker) (1361) Oct 8 19:51:22.387990 kernel: BTRFS info: devid 1 device path /dev/mapper/usr changed to /dev/dm-0 scanned by (udev-worker) (1352) Oct 8 19:51:22.391220 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:51:22.392987 kernel: BTRFS info: devid 1 device path /dev/dm-0 changed to /dev/mapper/usr scanned by (udev-worker) (1352) Oct 8 19:51:22.399182 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:51:22.400427 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:51:22.404671 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 8 19:51:22.414296 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Oct 8 19:51:22.416632 systemd[1]: update-ca-certificates.service - Update CA bundle at /etc/ssl/certs/ca-certificates.crt was skipped because of an unmet condition check (ConditionPathIsSymbolicLink=!/etc/ssl/certs/ca-certificates.crt). Oct 8 19:51:22.417746 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:51:22.417922 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:51:22.420925 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 8 19:51:22.421223 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 8 19:51:22.423242 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:51:22.423372 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:51:22.428252 systemd[1]: Condition check resulted in dev-ttyAMA0.device - /dev/ttyAMA0 being skipped. Oct 8 19:51:22.443561 systemd-resolved[1313]: Positive Trust Anchors: Oct 8 19:51:22.443576 systemd-resolved[1313]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 8 19:51:22.443608 systemd-resolved[1313]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 8 19:51:22.444521 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:51:22.444729 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:51:22.447281 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 8 19:51:22.447330 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 8 19:51:22.456425 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 8 19:51:22.457773 systemd-resolved[1313]: Defaulting to hostname 'linux'. Oct 8 19:51:22.468267 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Oct 8 19:51:22.471479 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 8 19:51:22.475890 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:51:22.497252 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:51:22.500006 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Oct 8 19:51:22.504391 systemd-networkd[1387]: lo: Link UP Oct 8 19:51:22.504405 systemd-networkd[1387]: lo: Gained carrier Oct 8 19:51:22.505181 systemd-networkd[1387]: Enumeration completed Oct 8 19:51:22.505259 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 8 19:51:22.506429 systemd-networkd[1387]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:51:22.506440 systemd-networkd[1387]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 8 19:51:22.506589 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Oct 8 19:51:22.507460 systemd-networkd[1387]: eth0: Link UP Oct 8 19:51:22.507469 systemd-networkd[1387]: eth0: Gained carrier Oct 8 19:51:22.507484 systemd-networkd[1387]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:51:22.508446 systemd[1]: Finished systemd-udev-settle.service - Wait for udev To Complete Device Initialization. Oct 8 19:51:22.510379 systemd[1]: Reached target network.target - Network. Oct 8 19:51:22.511639 systemd[1]: Reached target time-set.target - System Time Set. Oct 8 19:51:22.520202 systemd[1]: Starting lvm2-activation-early.service - Activation of LVM2 logical volumes... Oct 8 19:51:22.523022 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Oct 8 19:51:22.524486 systemd-networkd[1387]: eth0: DHCPv4 address 10.0.0.103/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 8 19:51:22.527265 systemd-timesyncd[1388]: Network configuration changed, trying to establish connection. Oct 8 19:51:22.528081 systemd-timesyncd[1388]: Contacted time server 10.0.0.1:123 (10.0.0.1). Oct 8 19:51:22.528138 systemd-timesyncd[1388]: Initial clock synchronization to Tue 2024-10-08 19:51:22.203417 UTC. Oct 8 19:51:22.542811 lvm[1405]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Oct 8 19:51:22.549902 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:51:22.577348 systemd[1]: Finished lvm2-activation-early.service - Activation of LVM2 logical volumes. Oct 8 19:51:22.578887 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:51:22.580081 systemd[1]: Reached target sysinit.target - System Initialization. Oct 8 19:51:22.581282 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Oct 8 19:51:22.582566 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Oct 8 19:51:22.584014 systemd[1]: Started logrotate.timer - Daily rotation of log files. Oct 8 19:51:22.585192 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Oct 8 19:51:22.586677 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Oct 8 19:51:22.587930 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Oct 8 19:51:22.587979 systemd[1]: Reached target paths.target - Path Units. Oct 8 19:51:22.588898 systemd[1]: Reached target timers.target - Timer Units. Oct 8 19:51:22.590663 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Oct 8 19:51:22.593236 systemd[1]: Starting docker.socket - Docker Socket for the API... Oct 8 19:51:22.601898 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Oct 8 19:51:22.604190 systemd[1]: Starting lvm2-activation.service - Activation of LVM2 logical volumes... Oct 8 19:51:22.605783 systemd[1]: Listening on docker.socket - Docker Socket for the API. Oct 8 19:51:22.607053 systemd[1]: Reached target sockets.target - Socket Units. Oct 8 19:51:22.608028 systemd[1]: Reached target basic.target - Basic System. Oct 8 19:51:22.609014 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Oct 8 19:51:22.609046 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Oct 8 19:51:22.609944 systemd[1]: Starting containerd.service - containerd container runtime... Oct 8 19:51:22.611898 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Oct 8 19:51:22.612054 lvm[1415]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Oct 8 19:51:22.614788 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Oct 8 19:51:22.617214 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Oct 8 19:51:22.618462 systemd[1]: flatcar-setup-environment.service - Modifies /etc/environment for CoreOS was skipped because of an unmet condition check (ConditionPathExists=/oem/bin/flatcar-setup-environment). Oct 8 19:51:22.620156 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Oct 8 19:51:22.622157 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Oct 8 19:51:22.626185 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Oct 8 19:51:22.631156 systemd[1]: Starting systemd-logind.service - User Login Management... Oct 8 19:51:22.631918 jq[1418]: false Oct 8 19:51:22.632869 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Oct 8 19:51:22.633299 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Oct 8 19:51:22.633917 systemd[1]: Starting update-engine.service - Update Engine... Oct 8 19:51:22.637045 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Oct 8 19:51:22.640263 systemd[1]: Finished lvm2-activation.service - Activation of LVM2 logical volumes. Oct 8 19:51:22.644326 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Oct 8 19:51:22.644479 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Oct 8 19:51:22.644629 jq[1429]: true Oct 8 19:51:22.645938 dbus-daemon[1417]: [system] SELinux support is enabled Oct 8 19:51:22.647019 systemd[1]: Started dbus.service - D-Bus System Message Bus. Oct 8 19:51:22.659595 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Oct 8 19:51:22.659799 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Oct 8 19:51:22.665205 systemd[1]: motdgen.service: Deactivated successfully. Oct 8 19:51:22.665879 jq[1435]: true Oct 8 19:51:22.666124 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Oct 8 19:51:22.669976 extend-filesystems[1419]: Found loop3 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found loop4 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found loop5 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda1 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda2 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda3 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found usr Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda4 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda6 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda7 Oct 8 19:51:22.669976 extend-filesystems[1419]: Found vda9 Oct 8 19:51:22.669976 extend-filesystems[1419]: Checking size of /dev/vda9 Oct 8 19:51:22.683464 (ntainerd)[1442]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR Oct 8 19:51:22.684348 systemd[1]: system-cloudinit@usr-share-oem-cloud\x2dconfig.yml.service - Load cloud-config from /usr/share/oem/cloud-config.yml was skipped because of an unmet condition check (ConditionFileNotEmpty=/usr/share/oem/cloud-config.yml). Oct 8 19:51:22.684396 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Oct 8 19:51:22.688311 systemd[1]: user-cloudinit-proc-cmdline.service - Load cloud-config from url defined in /proc/cmdline was skipped because of an unmet condition check (ConditionKernelCommandLine=cloud-config-url). Oct 8 19:51:22.688343 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Oct 8 19:51:22.691564 update_engine[1426]: I20241008 19:51:22.690940 1426 main.cc:92] Flatcar Update Engine starting Oct 8 19:51:22.694281 systemd[1]: Started update-engine.service - Update Engine. Oct 8 19:51:22.694613 update_engine[1426]: I20241008 19:51:22.694418 1426 update_check_scheduler.cc:74] Next update check in 8m11s Oct 8 19:51:22.696660 systemd[1]: Started locksmithd.service - Cluster reboot manager. Oct 8 19:51:22.699007 extend-filesystems[1419]: Resized partition /dev/vda9 Oct 8 19:51:22.711989 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 40 scanned by (udev-worker) (1364) Oct 8 19:51:22.713684 systemd-logind[1425]: Watching system buttons on /dev/input/event0 (Power Button) Oct 8 19:51:22.714577 extend-filesystems[1456]: resize2fs 1.47.1 (20-May-2024) Oct 8 19:51:22.714053 systemd-logind[1425]: New seat seat0. Oct 8 19:51:22.715286 systemd[1]: Started systemd-logind.service - User Login Management. Oct 8 19:51:22.730397 kernel: EXT4-fs (vda9): resizing filesystem from 553472 to 1864699 blocks Oct 8 19:51:22.774994 kernel: EXT4-fs (vda9): resized filesystem to 1864699 Oct 8 19:51:22.775908 locksmithd[1455]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Oct 8 19:51:22.786026 extend-filesystems[1456]: Filesystem at /dev/vda9 is mounted on /; on-line resizing required Oct 8 19:51:22.786026 extend-filesystems[1456]: old_desc_blocks = 1, new_desc_blocks = 1 Oct 8 19:51:22.786026 extend-filesystems[1456]: The filesystem on /dev/vda9 is now 1864699 (4k) blocks long. Oct 8 19:51:22.790006 extend-filesystems[1419]: Resized filesystem in /dev/vda9 Oct 8 19:51:22.789315 systemd[1]: extend-filesystems.service: Deactivated successfully. Oct 8 19:51:22.791914 bash[1467]: Updated "/home/core/.ssh/authorized_keys" Oct 8 19:51:22.789493 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Oct 8 19:51:22.792220 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Oct 8 19:51:22.795438 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Oct 8 19:51:22.891274 containerd[1442]: time="2024-10-08T19:51:22.891177840Z" level=info msg="starting containerd" revision=174e0d1785eeda18dc2beba45e1d5a188771636b version=v1.7.21 Oct 8 19:51:22.918306 containerd[1442]: time="2024-10-08T19:51:22.918253280Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.aufs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.919708 containerd[1442]: time="2024-10-08T19:51:22.919673240Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.aufs\"..." error="aufs is not supported (modprobe aufs failed: exit status 1 \"modprobe: FATAL: Module aufs not found in directory /lib/modules/6.6.54-flatcar\\n\"): skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:51:22.919708 containerd[1442]: time="2024-10-08T19:51:22.919708680Z" level=info msg="loading plugin \"io.containerd.event.v1.exchange\"..." type=io.containerd.event.v1 Oct 8 19:51:22.919790 containerd[1442]: time="2024-10-08T19:51:22.919723440Z" level=info msg="loading plugin \"io.containerd.internal.v1.opt\"..." type=io.containerd.internal.v1 Oct 8 19:51:22.919897 containerd[1442]: time="2024-10-08T19:51:22.919878160Z" level=info msg="loading plugin \"io.containerd.warning.v1.deprecations\"..." type=io.containerd.warning.v1 Oct 8 19:51:22.919920 containerd[1442]: time="2024-10-08T19:51:22.919902960Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.919989 containerd[1442]: time="2024-10-08T19:51:22.919958480Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." error="no scratch file generator: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920019 containerd[1442]: time="2024-10-08T19:51:22.919991520Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920178 containerd[1442]: time="2024-10-08T19:51:22.920158240Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." error="path /var/lib/containerd/io.containerd.snapshotter.v1.btrfs (ext4) must be a btrfs filesystem to be used with the btrfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920203 containerd[1442]: time="2024-10-08T19:51:22.920177920Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920203 containerd[1442]: time="2024-10-08T19:51:22.920191520Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." error="devmapper not configured: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920203 containerd[1442]: time="2024-10-08T19:51:22.920200720Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920288 containerd[1442]: time="2024-10-08T19:51:22.920273600Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920495 containerd[1442]: time="2024-10-08T19:51:22.920466680Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.zfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920603 containerd[1442]: time="2024-10-08T19:51:22.920585080Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.zfs\"..." error="path /var/lib/containerd/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:51:22.920635 containerd[1442]: time="2024-10-08T19:51:22.920602920Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1 Oct 8 19:51:22.920705 containerd[1442]: time="2024-10-08T19:51:22.920688600Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1 Oct 8 19:51:22.920747 containerd[1442]: time="2024-10-08T19:51:22.920735200Z" level=info msg="metadata content store policy set" policy=shared Oct 8 19:51:22.924512 containerd[1442]: time="2024-10-08T19:51:22.924479360Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1 Oct 8 19:51:22.924568 containerd[1442]: time="2024-10-08T19:51:22.924529920Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1 Oct 8 19:51:22.924568 containerd[1442]: time="2024-10-08T19:51:22.924546160Z" level=info msg="loading plugin \"io.containerd.lease.v1.manager\"..." type=io.containerd.lease.v1 Oct 8 19:51:22.924568 containerd[1442]: time="2024-10-08T19:51:22.924560680Z" level=info msg="loading plugin \"io.containerd.streaming.v1.manager\"..." type=io.containerd.streaming.v1 Oct 8 19:51:22.924625 containerd[1442]: time="2024-10-08T19:51:22.924575440Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." type=io.containerd.runtime.v1 Oct 8 19:51:22.924810 containerd[1442]: time="2024-10-08T19:51:22.924731400Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." type=io.containerd.monitor.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925362680Z" level=info msg="loading plugin \"io.containerd.runtime.v2.task\"..." type=io.containerd.runtime.v2 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925505720Z" level=info msg="loading plugin \"io.containerd.runtime.v2.shim\"..." type=io.containerd.runtime.v2 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925537000Z" level=info msg="loading plugin \"io.containerd.sandbox.store.v1.local\"..." type=io.containerd.sandbox.store.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925560680Z" level=info msg="loading plugin \"io.containerd.sandbox.controller.v1.local\"..." type=io.containerd.sandbox.controller.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925582760Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925599640Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925618160Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925637920Z" level=info msg="loading plugin \"io.containerd.service.v1.images-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925657840Z" level=info msg="loading plugin \"io.containerd.service.v1.introspection-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925674720Z" level=info msg="loading plugin \"io.containerd.service.v1.namespaces-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925713 containerd[1442]: time="2024-10-08T19:51:22.925696640Z" level=info msg="loading plugin \"io.containerd.service.v1.snapshots-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925956 containerd[1442]: time="2024-10-08T19:51:22.925713720Z" level=info msg="loading plugin \"io.containerd.service.v1.tasks-service\"..." type=io.containerd.service.v1 Oct 8 19:51:22.925956 containerd[1442]: time="2024-10-08T19:51:22.925926560Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.925956 containerd[1442]: time="2024-10-08T19:51:22.925948560Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.925956 containerd[1442]: time="2024-10-08T19:51:22.925974640Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.925991880Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.926011280Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.926025280Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.926037760Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.926052000Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926073 containerd[1442]: time="2024-10-08T19:51:22.926065360Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandbox-controllers\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926083360Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandboxes\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926095280Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926115720Z" level=info msg="loading plugin \"io.containerd.grpc.v1.streaming\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926129280Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926146560Z" level=info msg="loading plugin \"io.containerd.transfer.v1.local\"..." type=io.containerd.transfer.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926169720Z" level=info msg="loading plugin \"io.containerd.grpc.v1.transfer\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926185 containerd[1442]: time="2024-10-08T19:51:22.926182960Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.926311 containerd[1442]: time="2024-10-08T19:51:22.926194120Z" level=info msg="loading plugin \"io.containerd.internal.v1.restart\"..." type=io.containerd.internal.v1 Oct 8 19:51:22.926906 containerd[1442]: time="2024-10-08T19:51:22.926876520Z" level=info msg="loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." type=io.containerd.tracing.processor.v1 Oct 8 19:51:22.931494 containerd[1442]: time="2024-10-08T19:51:22.931466040Z" level=info msg="skip loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.tracing.processor.v1 Oct 8 19:51:22.931494 containerd[1442]: time="2024-10-08T19:51:22.931488080Z" level=info msg="loading plugin \"io.containerd.internal.v1.tracing\"..." type=io.containerd.internal.v1 Oct 8 19:51:22.931572 containerd[1442]: time="2024-10-08T19:51:22.931502040Z" level=info msg="skip loading plugin \"io.containerd.internal.v1.tracing\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.internal.v1 Oct 8 19:51:22.931572 containerd[1442]: time="2024-10-08T19:51:22.931512240Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.931572 containerd[1442]: time="2024-10-08T19:51:22.931527840Z" level=info msg="loading plugin \"io.containerd.nri.v1.nri\"..." type=io.containerd.nri.v1 Oct 8 19:51:22.931572 containerd[1442]: time="2024-10-08T19:51:22.931538880Z" level=info msg="NRI interface is disabled by configuration." Oct 8 19:51:22.931572 containerd[1442]: time="2024-10-08T19:51:22.931549160Z" level=info msg="loading plugin \"io.containerd.grpc.v1.cri\"..." type=io.containerd.grpc.v1 Oct 8 19:51:22.931887 containerd[1442]: time="2024-10-08T19:51:22.931821520Z" level=info msg="Start cri plugin with config {PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc DefaultRuntime:{Type: Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:} UntrustedWorkloadRuntime:{Type: Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:} Runtimes:map[runc:{Type:io.containerd.runc.v2 Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[SystemdCgroup:true] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:podsandbox}] NoPivot:false DisableSnapshotAnnotations:true DiscardUnpackedLayers:false IgnoreBlockIONotEnabledErrors:false IgnoreRdtNotEnabledErrors:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginSetupSerially:false NetworkPluginConfTemplate: IPPreference:} Registry:{ConfigPath: Mirrors:map[] Configs:map[] Auths:map[] Headers:map[]} ImageDecryption:{KeyModel:node} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:true SelinuxCategoryRange:1024 SandboxImage:registry.k8s.io/pause:3.8 StatsCollectPeriod:10 SystemdCgroup:false EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false UnsetSeccompProfile: TolerateMissingHugetlbController:true DisableHugetlbController:true DeviceOwnershipFromSecurityContext:false IgnoreImageDefinedVolumes:false NetNSMountsUnderStateDir:false EnableUnprivilegedPorts:false EnableUnprivilegedICMP:false EnableCDI:false CDISpecDirs:[/etc/cdi /var/run/cdi] ImagePullProgressTimeout:5m0s DrainExecSyncIOTimeout:0s ImagePullWithSyncFs:false IgnoreDeprecationWarnings:[]} ContainerdRootDir:/var/lib/containerd ContainerdEndpoint:/run/containerd/containerd.sock RootDir:/var/lib/containerd/io.containerd.grpc.v1.cri StateDir:/run/containerd/io.containerd.grpc.v1.cri}" Oct 8 19:51:22.932009 containerd[1442]: time="2024-10-08T19:51:22.931920080Z" level=info msg="Connect containerd service" Oct 8 19:51:22.932009 containerd[1442]: time="2024-10-08T19:51:22.931953040Z" level=info msg="using legacy CRI server" Oct 8 19:51:22.932009 containerd[1442]: time="2024-10-08T19:51:22.931978880Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Oct 8 19:51:22.932094 containerd[1442]: time="2024-10-08T19:51:22.932075360Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\"" Oct 8 19:51:22.932956 containerd[1442]: time="2024-10-08T19:51:22.932916360Z" level=error msg="failed to load cni during init, please check CRI plugin status before setting up network for pods" error="cni config load failed: no network config found in /etc/cni/net.d: cni plugin not initialized: failed to load cni config" Oct 8 19:51:22.933232 containerd[1442]: time="2024-10-08T19:51:22.933188360Z" level=info msg="Start subscribing containerd event" Oct 8 19:51:22.933262 containerd[1442]: time="2024-10-08T19:51:22.933241320Z" level=info msg="Start recovering state" Oct 8 19:51:22.933504 containerd[1442]: time="2024-10-08T19:51:22.933309880Z" level=info msg="Start event monitor" Oct 8 19:51:22.933504 containerd[1442]: time="2024-10-08T19:51:22.933331200Z" level=info msg="Start snapshots syncer" Oct 8 19:51:22.933504 containerd[1442]: time="2024-10-08T19:51:22.933344360Z" level=info msg="Start cni network conf syncer for default" Oct 8 19:51:22.933504 containerd[1442]: time="2024-10-08T19:51:22.933352720Z" level=info msg="Start streaming server" Oct 8 19:51:22.934173 containerd[1442]: time="2024-10-08T19:51:22.934151560Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Oct 8 19:51:22.934212 containerd[1442]: time="2024-10-08T19:51:22.934203000Z" level=info msg=serving... address=/run/containerd/containerd.sock Oct 8 19:51:22.936996 containerd[1442]: time="2024-10-08T19:51:22.935803040Z" level=info msg="containerd successfully booted in 0.046131s" Oct 8 19:51:22.934359 systemd[1]: Started containerd.service - containerd container runtime. Oct 8 19:51:23.938080 systemd-networkd[1387]: eth0: Gained IPv6LL Oct 8 19:51:23.940463 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Oct 8 19:51:23.942312 systemd[1]: Reached target network-online.target - Network is Online. Oct 8 19:51:23.950244 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Oct 8 19:51:23.955180 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... Oct 8 19:51:23.959034 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Oct 8 19:51:23.975224 systemd[1]: coreos-metadata.service: Deactivated successfully. Oct 8 19:51:23.977337 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Oct 8 19:51:23.979535 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Oct 8 19:51:23.980606 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Oct 8 19:51:24.416632 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent. Oct 8 19:51:24.420120 (kubelet)[1506]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_EXTRA_ARGS, KUBELET_KUBEADM_ARGS Oct 8 19:51:24.862651 kubelet[1506]: E1008 19:51:24.862517 1506 run.go:74] "command failed" err="failed to load kubelet config file, path: /var/lib/kubelet/config.yaml, error: failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" Oct 8 19:51:24.865350 systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE Oct 8 19:51:24.865493 systemd[1]: kubelet.service: Failed with result 'exit-code'. Oct 8 19:51:24.910433 sshd_keygen[1440]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Oct 8 19:51:24.928381 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Oct 8 19:51:24.937211 systemd[1]: Starting issuegen.service - Generate /run/issue... Oct 8 19:51:24.943507 systemd[1]: issuegen.service: Deactivated successfully. Oct 8 19:51:24.943680 systemd[1]: Finished issuegen.service - Generate /run/issue. Oct 8 19:51:24.946305 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Oct 8 19:51:24.957537 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Oct 8 19:51:24.972264 systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 8 19:51:24.974399 systemd[1]: Started serial-getty@ttyAMA0.service - Serial Getty on ttyAMA0. Oct 8 19:51:24.975708 systemd[1]: Reached target getty.target - Login Prompts. Oct 8 19:51:24.976761 systemd[1]: Reached target multi-user.target - Multi-User System. Oct 8 19:51:24.981187 systemd[1]: Startup finished in 578ms (kernel) + 4.271s (initrd) + 4.032s (userspace) = 8.882s. Oct 8 19:51:29.060813 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Oct 8 19:51:29.062116 systemd[1]: Started sshd@0-10.0.0.103:22-10.0.0.1:36784.service - OpenSSH per-connection server daemon (10.0.0.1:36784). Oct 8 19:51:29.121377 sshd[1536]: Accepted publickey for core from 10.0.0.1 port 36784 ssh2: RSA SHA256:PeFR0GwG3Km7u6+IJymPx7tkM/vpusnYsvzmiMSzq3A Oct 8 19:51:29.123194 sshd[1536]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:51:29.133138 systemd-logind[1425]: New session 1 of user core. Oct 8 19:51:29.134151 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Oct 8 19:51:29.142204 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Oct 8 19:51:29.152997 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Oct 8 19:51:29.155224 systemd[1]: Starting user@500.service - User Manager for UID 500... Oct 8 19:51:29.162156 (systemd)[1540]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Oct 8 19:51:29.233516 systemd[1540]: Queued start job for default target default.target. Oct 8 19:51:29.242883 systemd[1540]: Created slice app.slice - User Application Slice. Oct 8 19:51:29.242925 systemd[1540]: Reached target paths.target - Paths. Oct 8 19:51:29.242937 systemd[1540]: Reached target timers.target - Timers. Oct 8 19:51:29.244217 systemd[1540]: Starting dbus.socket - D-Bus User Message Bus Socket... Oct 8 19:51:29.254478 systemd[1540]: Listening on dbus.socket - D-Bus User Message Bus Socket. Oct 8 19:51:29.254544 systemd[1540]: Reached target sockets.target - Sockets. Oct 8 19:51:29.254555 systemd[1540]: Reached target basic.target - Basic System. Oct 8 19:51:29.254592 systemd[1540]: Reached target default.target - Main User Target. Oct 8 19:51:29.254619 systemd[1540]: Startup finished in 87ms. Oct 8 19:51:29.254929 systemd[1]: Started user@500.service - User Manager for UID 500. Oct 8 19:51:29.256381 systemd[1]: Started session-1.scope - Session 1 of User core. Oct 8 19:51:29.318661 systemd[1]: Started sshd@1-10.0.0.103:22-10.0.0.1:36800.service - OpenSSH per-connection server daemon (10.0.0.1:36800). Oct 8 19:51:29.365524 sshd[1551]: Accepted publickey for core from 10.0.0.1 port 36800 ssh2: RSA SHA256:PeFR0GwG3Km7u6+IJymPx7tkM/vpusnYsvzmiMSzq3A Oct 8 19:51:29.367052 sshd[1551]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:51:29.371050 systemd-logind[1425]: New session 2 of user core. Oct 8 19:51:29.380154 systemd[1]: Started session-2.scope - Session 2 of User core. Oct 8 19:51:29.433289 sshd[1551]: pam_unix(sshd:session): session closed for user core Oct 8 19:51:29.440030 systemd[1]: sshd@1-10.0.0.103:22-10.0.0.1:36800.service: Deactivated successfully. Oct 8 19:51:29.442384 systemd[1]: session-2.scope: Deactivated successfully. Oct 8 19:51:29.445106 systemd-logind[1425]: Session 2 logged out. Waiting for processes to exit. Oct 8 19:51:29.455265 systemd[1]: Started sshd@2-10.0.0.103:22-10.0.0.1:36812.service - OpenSSH per-connection server daemon (10.0.0.1:36812). Oct 8 19:51:29.456168 systemd-logind[1425]: Removed session 2. Oct 8 19:51:29.487884 sshd[1558]: Accepted publickey for core from 10.0.0.1 port 36812 ssh2: RSA SHA256:PeFR0GwG3Km7u6+IJymPx7tkM/vpusnYsvzmiMSzq3A Oct 8 19:51:29.489283 sshd[1558]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:51:29.493040 systemd-logind[1425]: New session 3 of user core. Oct 8 19:51:29.501126 systemd[1]: Started session-3.scope - Session 3 of User core. Oct 8 19:51:29.547844 sshd[1558]: pam_unix(sshd:session): session closed for user core Oct 8 19:51:29.563228 systemd[1]: sshd@2-10.0.0.103:22-10.0.0.1:36812.service: Deactivated successfully. Oct 8 19:51:29.564603 systemd[1]: session-3.scope: Deactivated successfully. Oct 8 19:51:29.566004 systemd-logind[1425]: Session 3 logged out. Waiting for processes to exit. Oct 8 19:51:29.567035 systemd[1]: Started sshd@3-10.0.0.103:22-10.0.0.1:36828.service - OpenSSH per-connection server daemon (10.0.0.1:36828). Oct 8 19:51:29.567787 systemd-logind[1425]: Removed session 3. Oct 8 19:51:29.602314 sshd[1565]: Accepted publickey for core from 10.0.0.1 port 36828 ssh2: RSA SHA256:PeFR0GwG3Km7u6+IJymPx7tkM/vpusnYsvzmiMSzq3A Oct 8 19:51:29.603575 sshd[1565]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:51:29.607610 systemd-logind[1425]: New session 4 of user core. Oct 8 19:51:29.622141 systemd[1]: Started session-4.scope - Session 4 of User core. Oct 8 19:51:29.673262 sshd[1565]: pam_unix(sshd:session): session closed for user core Oct 8 19:51:29.683207 systemd[1]: sshd@3-10.0.0.103:22-10.0.0.1:36828.service: Deactivated successfully. Oct 8 19:51:29.684583 systemd[1]: session-4.scope: Deactivated successfully. Oct 8 19:51:29.685701 systemd-logind[1425]: Session 4 logged out. Waiting for processes to exit. Oct 8 19:51:29.686690 systemd[1]: Started sshd@4-10.0.0.103:22-10.0.0.1:36840.service - OpenSSH per-connection server daemon (10.0.0.1:36840). Oct 8 19:51:29.687504 systemd-logind[1425]: Removed session 4. Oct 8 19:51:29.721078 sshd[1572]: Accepted publickey for core from 10.0.0.1 port 36840 ssh2: RSA SHA256:PeFR0GwG3Km7u6+IJymPx7tkM/vpusnYsvzmiMSzq3A Oct 8 19:51:29.722277 sshd[1572]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:51:29.726044 systemd-logind[1425]: New session 5 of user core. Oct 8 19:51:29.735252 systemd[1]: Started session-5.scope - Session 5 of User core. Oct 8 19:51:29.792153 sudo[1575]: core : PWD=/home/core ; USER=root ; COMMAND=/home/core/install.sh Oct 8 19:51:29.792719 sudo[1575]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Oct 8 19:51:29.818256 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Oct 8 19:51:29.833462 systemd[1]: coreos-metadata.service: Deactivated successfully. Oct 8 19:51:29.833692 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Oct 8 19:51:30.319180 systemd[1]: Stopped kubelet.service - kubelet: The Kubernetes Node Agent. Oct 8 19:51:30.329179 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... Oct 8 19:51:30.344990 systemd[1]: Reloading requested from client PID 1624 ('systemctl') (unit session-5.scope)... Oct 8 19:51:30.345008 systemd[1]: Reloading... Oct 8 19:51:30.409054 zram_generator::config[1658]: No configuration found. Oct 8 19:51:30.578050 systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, updating /var/run/docker.sock → /run/docker.sock; please update the unit file accordingly. Oct 8 19:51:30.628872 systemd[1]: Reloading finished in 283 ms. Oct 8 19:51:30.664420 systemd[1]: kubelet.service: Control process exited, code=killed, status=15/TERM Oct 8 19:51:30.664484 systemd[1]: kubelet.service: Failed with result 'signal'. Oct 8 19:51:30.664691 systemd[1]: Stopped kubelet.service - kubelet: The Kubernetes Node Agent. Oct 8 19:51:30.666863 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... Oct 8 19:51:30.757315 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent. Oct 8 19:51:30.761768 (kubelet)[1708]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_EXTRA_ARGS Oct 8 19:51:30.801353 kubelet[1708]: Flag --container-runtime-endpoint has been deprecated, This parameter should be set via the config file specified by the Kubelet's --config flag. See https://kubernetes.io/docs/tasks/administer-cluster/kubelet-config-file/ for more information. Oct 8 19:51:30.801353 kubelet[1708]: Flag --pod-infra-container-image has been deprecated, will be removed in a future release. Image garbage collector will get sandbox image information from CRI. Oct 8 19:51:30.801353 kubelet[1708]: Flag --volume-plugin-dir has been deprecated, This parameter should be set via the config file specified by the Kubelet's --config flag. See https://kubernetes.io/docs/tasks/administer-cluster/kubelet-config-file/ for more information. Oct 8 19:51:30.801692 kubelet[1708]: I1008 19:51:30.801387 1708 server.go:204] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime" Oct 8 19:51:31.830033 kubelet[1708]: I1008 19:51:31.829997 1708 server.go:487] "Kubelet version" kubeletVersion="v1.29.2" Oct 8 19:51:31.830033 kubelet[1708]: I1008 19:51:31.830030 1708 server.go:489] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" Oct 8 19:51:31.830348 kubelet[1708]: I1008 19:51:31.830238 1708 server.go:919] "Client rotation is on, will bootstrap in background" Oct 8 19:51:31.874730 kubelet[1708]: I1008 19:51:31.873825 1708 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/etc/kubernetes/pki/ca.crt" Oct 8 19:51:31.889754 kubelet[1708]: I1008 19:51:31.889717 1708 server.go:745] "--cgroups-per-qos enabled, but --cgroup-root was not specified. defaulting to /" Oct 8 19:51:31.889969 kubelet[1708]: I1008 19:51:31.889941 1708 container_manager_linux.go:265] "Container manager verified user specified cgroup-root exists" cgroupRoot=[] Oct 8 19:51:31.890167 kubelet[1708]: I1008 19:51:31.890141 1708 container_manager_linux.go:270] "Creating Container Manager object based on Node Config" nodeConfig={"RuntimeCgroupsName":"","SystemCgroupsName":"","KubeletCgroupsName":"","KubeletOOMScoreAdj":-999,"ContainerRuntime":"","CgroupsPerQOS":true,"CgroupRoot":"/","CgroupDriver":"systemd","KubeletRootDir":"/var/lib/kubelet","ProtectKernelDefaults":false,"KubeReservedCgroupName":"","SystemReservedCgroupName":"","ReservedSystemCPUs":{},"EnforceNodeAllocatable":{"pods":{}},"KubeReserved":null,"SystemReserved":null,"HardEvictionThresholds":[{"Signal":"memory.available","Operator":"LessThan","Value":{"Quantity":"100Mi","Percentage":0},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.1},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.inodesFree","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.15},"GracePeriod":0,"MinReclaim":null}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"ExperimentalMemoryManagerPolicy":"None","ExperimentalMemoryManagerReservedMemory":null,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null} Oct 8 19:51:31.890167 kubelet[1708]: I1008 19:51:31.890162 1708 topology_manager.go:138] "Creating topology manager with none policy" Oct 8 19:51:31.890265 kubelet[1708]: I1008 19:51:31.890171 1708 container_manager_linux.go:301] "Creating device plugin manager" Oct 8 19:51:31.891316 kubelet[1708]: I1008 19:51:31.891283 1708 state_mem.go:36] "Initialized new in-memory state store" Oct 8 19:51:31.895328 kubelet[1708]: I1008 19:51:31.895300 1708 kubelet.go:396] "Attempting to sync node with API server" Oct 8 19:51:31.895399 kubelet[1708]: I1008 19:51:31.895339 1708 kubelet.go:301] "Adding static pod path" path="/etc/kubernetes/manifests" Oct 8 19:51:31.895399 kubelet[1708]: I1008 19:51:31.895361 1708 kubelet.go:312] "Adding apiserver pod source" Oct 8 19:51:31.895399 kubelet[1708]: I1008 19:51:31.895375 1708 apiserver.go:42] "Waiting for node sync before watching apiserver pods" Oct 8 19:51:31.895611 kubelet[1708]: E1008 19:51:31.895561 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:31.895611 kubelet[1708]: E1008 19:51:31.895588 1708 file.go:98] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:31.897057 kubelet[1708]: I1008 19:51:31.897036 1708 kuberuntime_manager.go:258] "Container runtime initialized" containerRuntime="containerd" version="v1.7.21" apiVersion="v1" Oct 8 19:51:31.897553 kubelet[1708]: I1008 19:51:31.897525 1708 kubelet.go:809] "Not starting ClusterTrustBundle informer because we are in static kubelet mode" Oct 8 19:51:31.898082 kubelet[1708]: W1008 19:51:31.898060 1708 probe.go:268] Flexvolume plugin directory at /opt/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating. Oct 8 19:51:31.899059 kubelet[1708]: I1008 19:51:31.898875 1708 server.go:1256] "Started kubelet" Oct 8 19:51:31.899333 kubelet[1708]: I1008 19:51:31.899297 1708 ratelimit.go:55] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=10 Oct 8 19:51:31.899774 kubelet[1708]: I1008 19:51:31.899486 1708 server.go:162] "Starting to listen" address="0.0.0.0" port=10250 Oct 8 19:51:31.900253 kubelet[1708]: I1008 19:51:31.900098 1708 server.go:233] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock" Oct 8 19:51:31.900308 kubelet[1708]: I1008 19:51:31.900279 1708 server.go:461] "Adding debug handlers to kubelet server" Oct 8 19:51:31.900521 kubelet[1708]: I1008 19:51:31.900494 1708 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer" Oct 8 19:51:31.905311 kubelet[1708]: I1008 19:51:31.905280 1708 volume_manager.go:291] "Starting Kubelet Volume Manager" Oct 8 19:51:31.905708 kubelet[1708]: I1008 19:51:31.905690 1708 desired_state_of_world_populator.go:151] "Desired state populator starts to run" Oct 8 19:51:31.906119 kubelet[1708]: I1008 19:51:31.905845 1708 reconciler_new.go:29] "Reconciler: start to sync state" Oct 8 19:51:31.908775 kubelet[1708]: I1008 19:51:31.907699 1708 factory.go:221] Registration of the systemd container factory successfully Oct 8 19:51:31.908775 kubelet[1708]: I1008 19:51:31.907779 1708 factory.go:219] Registration of the crio container factory failed: Get "http://%2Fvar%2Frun%2Fcrio%2Fcrio.sock/info": dial unix /var/run/crio/crio.sock: connect: no such file or directory Oct 8 19:51:31.909786 kubelet[1708]: W1008 19:51:31.909762 1708 reflector.go:539] vendor/k8s.io/client-go/informers/factory.go:159: failed to list *v1.Node: nodes "10.0.0.103" is forbidden: User "system:anonymous" cannot list resource "nodes" in API group "" at the cluster scope Oct 8 19:51:31.909786 kubelet[1708]: E1008 19:51:31.909789 1708 reflector.go:147] vendor/k8s.io/client-go/informers/factory.go:159: Failed to watch *v1.Node: failed to list *v1.Node: nodes "10.0.0.103" is forbidden: User "system:anonymous" cannot list resource "nodes" in API group "" at the cluster scope Oct 8 19:51:31.909882 kubelet[1708]: E1008 19:51:31.909865 1708 kubelet.go:1462] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem" Oct 8 19:51:31.910085 kubelet[1708]: W1008 19:51:31.910070 1708 reflector.go:539] vendor/k8s.io/client-go/informers/factory.go:159: failed to list *v1.Service: services is forbidden: User "system:anonymous" cannot list resource "services" in API group "" at the cluster scope Oct 8 19:51:31.910128 kubelet[1708]: E1008 19:51:31.910089 1708 reflector.go:147] vendor/k8s.io/client-go/informers/factory.go:159: Failed to watch *v1.Service: failed to list *v1.Service: services is forbidden: User "system:anonymous" cannot list resource "services" in API group "" at the cluster scope Oct 8 19:51:31.910676 kubelet[1708]: E1008 19:51:31.910648 1708 event.go:346] "Server rejected event (will not retry!)" err="events is forbidden: User \"system:anonymous\" cannot create resource \"events\" in API group \"\" in the namespace \"default\"" event="&Event{ObjectMeta:{10.0.0.103.17fc923002582e65 default 0 0001-01-01 00:00:00 +0000 UTC map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:10.0.0.103,UID:10.0.0.103,APIVersion:,ResourceVersion:,FieldPath:,},Reason:Starting,Message:Starting kubelet.,Source:EventSource{Component:kubelet,Host:10.0.0.103,},FirstTimestamp:2024-10-08 19:51:31.898846821 +0000 UTC m=+1.133472540,LastTimestamp:2024-10-08 19:51:31.898846821 +0000 UTC m=+1.133472540,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:10.0.0.103,}" Oct 8 19:51:31.911086 kubelet[1708]: I1008 19:51:31.911066 1708 factory.go:221] Registration of the containerd container factory successfully Oct 8 19:51:31.924273 kubelet[1708]: E1008 19:51:31.924240 1708 nodelease.go:49] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"10.0.0.103\" not found" node="10.0.0.103" Oct 8 19:51:31.926475 kubelet[1708]: I1008 19:51:31.925384 1708 cpu_manager.go:214] "Starting CPU manager" policy="none" Oct 8 19:51:31.926475 kubelet[1708]: I1008 19:51:31.925406 1708 cpu_manager.go:215] "Reconciling" reconcilePeriod="10s" Oct 8 19:51:31.926475 kubelet[1708]: I1008 19:51:31.925423 1708 state_mem.go:36] "Initialized new in-memory state store" Oct 8 19:51:31.994375 kubelet[1708]: I1008 19:51:31.994337 1708 policy_none.go:49] "None policy: Start" Oct 8 19:51:31.995136 kubelet[1708]: I1008 19:51:31.995119 1708 memory_manager.go:170] "Starting memorymanager" policy="None" Oct 8 19:51:31.995192 kubelet[1708]: I1008 19:51:31.995169 1708 state_mem.go:35] "Initializing new in-memory state store" Oct 8 19:51:32.002860 systemd[1]: Created slice kubepods.slice - libcontainer container kubepods.slice. Oct 8 19:51:32.007197 kubelet[1708]: I1008 19:51:32.006944 1708 kubelet_node_status.go:73] "Attempting to register node" node="10.0.0.103" Oct 8 19:51:32.012880 systemd[1]: Created slice kubepods-besteffort.slice - libcontainer container kubepods-besteffort.slice. Oct 8 19:51:32.017449 kubelet[1708]: I1008 19:51:32.017422 1708 kubelet_node_status.go:76] "Successfully registered node" node="10.0.0.103" Oct 8 19:51:32.019075 kubelet[1708]: I1008 19:51:32.019052 1708 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv4" Oct 8 19:51:32.020176 kubelet[1708]: I1008 19:51:32.020121 1708 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv6" Oct 8 19:51:32.020176 kubelet[1708]: I1008 19:51:32.020140 1708 status_manager.go:217] "Starting to sync pod status with apiserver" Oct 8 19:51:32.020176 kubelet[1708]: I1008 19:51:32.020154 1708 kubelet.go:2329] "Starting kubelet main sync loop" Oct 8 19:51:32.020400 kubelet[1708]: E1008 19:51:32.020314 1708 kubelet.go:2353] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]" Oct 8 19:51:32.022159 systemd[1]: Created slice kubepods-burstable.slice - libcontainer container kubepods-burstable.slice. Oct 8 19:51:32.024399 kubelet[1708]: I1008 19:51:32.024227 1708 manager.go:479] "Failed to read data from checkpoint" checkpoint="kubelet_internal_checkpoint" err="checkpoint is not found" Oct 8 19:51:32.025002 kubelet[1708]: I1008 19:51:32.024977 1708 plugin_manager.go:118] "Starting Kubelet Plugin Manager" Oct 8 19:51:32.025913 kubelet[1708]: E1008 19:51:32.025891 1708 eviction_manager.go:282] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"10.0.0.103\" not found" Oct 8 19:51:32.037845 kubelet[1708]: E1008 19:51:32.037813 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.138684 kubelet[1708]: E1008 19:51:32.138514 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.238933 kubelet[1708]: E1008 19:51:32.238864 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.339326 kubelet[1708]: E1008 19:51:32.339280 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.439911 kubelet[1708]: E1008 19:51:32.439807 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.540404 kubelet[1708]: E1008 19:51:32.540327 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.640820 kubelet[1708]: E1008 19:51:32.640776 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.741142 kubelet[1708]: E1008 19:51:32.741056 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.832488 kubelet[1708]: I1008 19:51:32.832448 1708 transport.go:147] "Certificate rotation detected, shutting down client connections to start using new credentials" Oct 8 19:51:32.832776 kubelet[1708]: W1008 19:51:32.832625 1708 reflector.go:462] vendor/k8s.io/client-go/informers/factory.go:159: watch of *v1.RuntimeClass ended with: very short watch: vendor/k8s.io/client-go/informers/factory.go:159: Unexpected watch close - watch lasted less than a second and no items received Oct 8 19:51:32.832776 kubelet[1708]: W1008 19:51:32.832669 1708 reflector.go:462] vendor/k8s.io/client-go/informers/factory.go:159: watch of *v1.CSIDriver ended with: very short watch: vendor/k8s.io/client-go/informers/factory.go:159: Unexpected watch close - watch lasted less than a second and no items received Oct 8 19:51:32.841613 kubelet[1708]: E1008 19:51:32.841587 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:32.895908 kubelet[1708]: E1008 19:51:32.895862 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:32.941980 kubelet[1708]: E1008 19:51:32.941942 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.042577 kubelet[1708]: E1008 19:51:33.042476 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.142867 kubelet[1708]: E1008 19:51:33.142815 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.243101 kubelet[1708]: E1008 19:51:33.243074 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.278855 sudo[1575]: pam_unix(sudo:session): session closed for user root Oct 8 19:51:33.281151 sshd[1572]: pam_unix(sshd:session): session closed for user core Oct 8 19:51:33.284227 systemd[1]: sshd@4-10.0.0.103:22-10.0.0.1:36840.service: Deactivated successfully. Oct 8 19:51:33.285686 systemd[1]: session-5.scope: Deactivated successfully. Oct 8 19:51:33.286252 systemd-logind[1425]: Session 5 logged out. Waiting for processes to exit. Oct 8 19:51:33.287116 systemd-logind[1425]: Removed session 5. Oct 8 19:51:33.343537 kubelet[1708]: E1008 19:51:33.343422 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.443902 kubelet[1708]: E1008 19:51:33.443850 1708 kubelet_node_status.go:462] "Error getting the current node from lister" err="node \"10.0.0.103\" not found" Oct 8 19:51:33.544853 kubelet[1708]: I1008 19:51:33.544826 1708 kuberuntime_manager.go:1529] "Updating runtime config through cri with podcidr" CIDR="192.168.1.0/24" Oct 8 19:51:33.545143 containerd[1442]: time="2024-10-08T19:51:33.545105175Z" level=info msg="No cni config template is specified, wait for other system components to drop the config." Oct 8 19:51:33.545819 kubelet[1708]: I1008 19:51:33.545613 1708 kubelet_network.go:61] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="192.168.1.0/24" Oct 8 19:51:33.896119 kubelet[1708]: E1008 19:51:33.896064 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:33.896119 kubelet[1708]: I1008 19:51:33.896072 1708 apiserver.go:52] "Watching apiserver" Oct 8 19:51:33.899586 kubelet[1708]: I1008 19:51:33.899563 1708 topology_manager.go:215] "Topology Admit Handler" podUID="a1ac08f9-1b25-4d86-8349-d78ca732c652" podNamespace="kube-flannel" podName="kube-flannel-ds-9vcs4" Oct 8 19:51:33.899660 kubelet[1708]: I1008 19:51:33.899648 1708 topology_manager.go:215] "Topology Admit Handler" podUID="4b0c2ca9-97eb-4a25-9b85-f4fb07e57254" podNamespace="kube-system" podName="kube-proxy-v4klm" Oct 8 19:51:33.905923 systemd[1]: Created slice kubepods-besteffort-pod4b0c2ca9_97eb_4a25_9b85_f4fb07e57254.slice - libcontainer container kubepods-besteffort-pod4b0c2ca9_97eb_4a25_9b85_f4fb07e57254.slice. Oct 8 19:51:33.906046 kubelet[1708]: I1008 19:51:33.906020 1708 desired_state_of_world_populator.go:159] "Finished populating initial desired state of world" Oct 8 19:51:33.915167 kubelet[1708]: I1008 19:51:33.915134 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"run\" (UniqueName: \"kubernetes.io/host-path/a1ac08f9-1b25-4d86-8349-d78ca732c652-run\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915249 kubelet[1708]: I1008 19:51:33.915175 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"flannel-cfg\" (UniqueName: \"kubernetes.io/configmap/a1ac08f9-1b25-4d86-8349-d78ca732c652-flannel-cfg\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915249 kubelet[1708]: I1008 19:51:33.915202 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-rz2m4\" (UniqueName: \"kubernetes.io/projected/a1ac08f9-1b25-4d86-8349-d78ca732c652-kube-api-access-rz2m4\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915249 kubelet[1708]: I1008 19:51:33.915222 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-proxy\" (UniqueName: \"kubernetes.io/configmap/4b0c2ca9-97eb-4a25-9b85-f4fb07e57254-kube-proxy\") pod \"kube-proxy-v4klm\" (UID: \"4b0c2ca9-97eb-4a25-9b85-f4fb07e57254\") " pod="kube-system/kube-proxy-v4klm" Oct 8 19:51:33.915249 kubelet[1708]: I1008 19:51:33.915243 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"xtables-lock\" (UniqueName: \"kubernetes.io/host-path/4b0c2ca9-97eb-4a25-9b85-f4fb07e57254-xtables-lock\") pod \"kube-proxy-v4klm\" (UID: \"4b0c2ca9-97eb-4a25-9b85-f4fb07e57254\") " pod="kube-system/kube-proxy-v4klm" Oct 8 19:51:33.915334 kubelet[1708]: I1008 19:51:33.915268 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"lib-modules\" (UniqueName: \"kubernetes.io/host-path/4b0c2ca9-97eb-4a25-9b85-f4fb07e57254-lib-modules\") pod \"kube-proxy-v4klm\" (UID: \"4b0c2ca9-97eb-4a25-9b85-f4fb07e57254\") " pod="kube-system/kube-proxy-v4klm" Oct 8 19:51:33.915334 kubelet[1708]: I1008 19:51:33.915286 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"cni-plugin\" (UniqueName: \"kubernetes.io/host-path/a1ac08f9-1b25-4d86-8349-d78ca732c652-cni-plugin\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915334 kubelet[1708]: I1008 19:51:33.915303 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"cni\" (UniqueName: \"kubernetes.io/host-path/a1ac08f9-1b25-4d86-8349-d78ca732c652-cni\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915334 kubelet[1708]: I1008 19:51:33.915320 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"xtables-lock\" (UniqueName: \"kubernetes.io/host-path/a1ac08f9-1b25-4d86-8349-d78ca732c652-xtables-lock\") pod \"kube-flannel-ds-9vcs4\" (UID: \"a1ac08f9-1b25-4d86-8349-d78ca732c652\") " pod="kube-flannel/kube-flannel-ds-9vcs4" Oct 8 19:51:33.915406 kubelet[1708]: I1008 19:51:33.915338 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-9mkvb\" (UniqueName: \"kubernetes.io/projected/4b0c2ca9-97eb-4a25-9b85-f4fb07e57254-kube-api-access-9mkvb\") pod \"kube-proxy-v4klm\" (UID: \"4b0c2ca9-97eb-4a25-9b85-f4fb07e57254\") " pod="kube-system/kube-proxy-v4klm" Oct 8 19:51:33.923877 systemd[1]: Created slice kubepods-burstable-poda1ac08f9_1b25_4d86_8349_d78ca732c652.slice - libcontainer container kubepods-burstable-poda1ac08f9_1b25_4d86_8349_d78ca732c652.slice. Oct 8 19:51:34.223216 kubelet[1708]: E1008 19:51:34.223097 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:34.223921 containerd[1442]: time="2024-10-08T19:51:34.223873048Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-proxy-v4klm,Uid:4b0c2ca9-97eb-4a25-9b85-f4fb07e57254,Namespace:kube-system,Attempt:0,}" Oct 8 19:51:34.236557 kubelet[1708]: E1008 19:51:34.236533 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:34.237070 containerd[1442]: time="2024-10-08T19:51:34.237025575Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-flannel-ds-9vcs4,Uid:a1ac08f9-1b25-4d86-8349-d78ca732c652,Namespace:kube-flannel,Attempt:0,}" Oct 8 19:51:34.722123 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount3353730998.mount: Deactivated successfully. Oct 8 19:51:34.728017 containerd[1442]: time="2024-10-08T19:51:34.727938706Z" level=info msg="ImageCreate event name:\"registry.k8s.io/pause:3.8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" Oct 8 19:51:34.729317 containerd[1442]: time="2024-10-08T19:51:34.729267341Z" level=info msg="stop pulling image registry.k8s.io/pause:3.8: active requests=0, bytes read=269175" Oct 8 19:51:34.732005 containerd[1442]: time="2024-10-08T19:51:34.731795230Z" level=info msg="ImageCreate event name:\"sha256:4e42fb3c9d90ed7895bc04a9d96fe3102a65b521f485cc5a4f3dd818afef9cef\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" Oct 8 19:51:34.733086 containerd[1442]: time="2024-10-08T19:51:34.733057014Z" level=info msg="ImageUpdate event name:\"registry.k8s.io/pause:3.8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" Oct 8 19:51:34.733589 containerd[1442]: time="2024-10-08T19:51:34.733548739Z" level=info msg="stop pulling image registry.k8s.io/pause:3.8: active requests=0, bytes read=0" Oct 8 19:51:34.735707 containerd[1442]: time="2024-10-08T19:51:34.735672081Z" level=info msg="ImageCreate event name:\"registry.k8s.io/pause@sha256:9001185023633d17a2f98ff69b6ff2615b8ea02a825adffa40422f51dfdcde9d\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" Oct 8 19:51:34.736605 containerd[1442]: time="2024-10-08T19:51:34.736459776Z" level=info msg="Pulled image \"registry.k8s.io/pause:3.8\" with image id \"sha256:4e42fb3c9d90ed7895bc04a9d96fe3102a65b521f485cc5a4f3dd818afef9cef\", repo tag \"registry.k8s.io/pause:3.8\", repo digest \"registry.k8s.io/pause@sha256:9001185023633d17a2f98ff69b6ff2615b8ea02a825adffa40422f51dfdcde9d\", size \"268403\" in 512.499786ms" Oct 8 19:51:34.739589 containerd[1442]: time="2024-10-08T19:51:34.739548418Z" level=info msg="Pulled image \"registry.k8s.io/pause:3.8\" with image id \"sha256:4e42fb3c9d90ed7895bc04a9d96fe3102a65b521f485cc5a4f3dd818afef9cef\", repo tag \"registry.k8s.io/pause:3.8\", repo digest \"registry.k8s.io/pause@sha256:9001185023633d17a2f98ff69b6ff2615b8ea02a825adffa40422f51dfdcde9d\", size \"268403\" in 502.44252ms" Oct 8 19:51:34.847561 containerd[1442]: time="2024-10-08T19:51:34.847416631Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:51:34.847561 containerd[1442]: time="2024-10-08T19:51:34.847508644Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:51:34.847561 containerd[1442]: time="2024-10-08T19:51:34.847531667Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:34.847845 containerd[1442]: time="2024-10-08T19:51:34.847627364Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:34.848059 containerd[1442]: time="2024-10-08T19:51:34.847763442Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:51:34.848059 containerd[1442]: time="2024-10-08T19:51:34.847834928Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:51:34.848059 containerd[1442]: time="2024-10-08T19:51:34.847851769Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:34.848059 containerd[1442]: time="2024-10-08T19:51:34.847986142Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:34.897250 kubelet[1708]: E1008 19:51:34.897183 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:34.934156 systemd[1]: Started cri-containerd-4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f.scope - libcontainer container 4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f. Oct 8 19:51:34.935496 systemd[1]: Started cri-containerd-5d0fb1eb415409816cded87e37d4b02af540b674001fd43f3db0ae4bf91c510c.scope - libcontainer container 5d0fb1eb415409816cded87e37d4b02af540b674001fd43f3db0ae4bf91c510c. Oct 8 19:51:34.953158 containerd[1442]: time="2024-10-08T19:51:34.953049795Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-proxy-v4klm,Uid:4b0c2ca9-97eb-4a25-9b85-f4fb07e57254,Namespace:kube-system,Attempt:0,} returns sandbox id \"5d0fb1eb415409816cded87e37d4b02af540b674001fd43f3db0ae4bf91c510c\"" Oct 8 19:51:34.954338 kubelet[1708]: E1008 19:51:34.954318 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:34.957509 containerd[1442]: time="2024-10-08T19:51:34.957344468Z" level=info msg="PullImage \"registry.k8s.io/kube-proxy:v1.29.9\"" Oct 8 19:51:34.964597 containerd[1442]: time="2024-10-08T19:51:34.964554378Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-flannel-ds-9vcs4,Uid:a1ac08f9-1b25-4d86-8349-d78ca732c652,Namespace:kube-flannel,Attempt:0,} returns sandbox id \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\"" Oct 8 19:51:34.965160 kubelet[1708]: E1008 19:51:34.965143 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:35.898242 kubelet[1708]: E1008 19:51:35.898177 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:36.898826 kubelet[1708]: E1008 19:51:36.898792 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:37.221187 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount1074224627.mount: Deactivated successfully. Oct 8 19:51:37.465355 containerd[1442]: time="2024-10-08T19:51:37.465286310Z" level=info msg="ImageCreate event name:\"registry.k8s.io/kube-proxy:v1.29.9\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:37.466262 containerd[1442]: time="2024-10-08T19:51:37.466217368Z" level=info msg="stop pulling image registry.k8s.io/kube-proxy:v1.29.9: active requests=0, bytes read=25254040" Oct 8 19:51:37.467462 containerd[1442]: time="2024-10-08T19:51:37.467410099Z" level=info msg="ImageCreate event name:\"sha256:0e8a375be0a8ed2d79dab5b4513dc4639ed6e7d3da10a53172b619355f666d4f\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:37.469650 containerd[1442]: time="2024-10-08T19:51:37.469611479Z" level=info msg="ImageCreate event name:\"registry.k8s.io/kube-proxy@sha256:124040dbe6b5294352355f5d34c692ecbc940cdc57a8fd06d0f38f76b6138906\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:37.470538 containerd[1442]: time="2024-10-08T19:51:37.470497023Z" level=info msg="Pulled image \"registry.k8s.io/kube-proxy:v1.29.9\" with image id \"sha256:0e8a375be0a8ed2d79dab5b4513dc4639ed6e7d3da10a53172b619355f666d4f\", repo tag \"registry.k8s.io/kube-proxy:v1.29.9\", repo digest \"registry.k8s.io/kube-proxy@sha256:124040dbe6b5294352355f5d34c692ecbc940cdc57a8fd06d0f38f76b6138906\", size \"25253057\" in 2.513016602s" Oct 8 19:51:37.470585 containerd[1442]: time="2024-10-08T19:51:37.470536574Z" level=info msg="PullImage \"registry.k8s.io/kube-proxy:v1.29.9\" returns image reference \"sha256:0e8a375be0a8ed2d79dab5b4513dc4639ed6e7d3da10a53172b619355f666d4f\"" Oct 8 19:51:37.471412 containerd[1442]: time="2024-10-08T19:51:37.471383920Z" level=info msg="PullImage \"docker.io/flannel/flannel-cni-plugin:v1.1.2\"" Oct 8 19:51:37.472801 containerd[1442]: time="2024-10-08T19:51:37.472697688Z" level=info msg="CreateContainer within sandbox \"5d0fb1eb415409816cded87e37d4b02af540b674001fd43f3db0ae4bf91c510c\" for container &ContainerMetadata{Name:kube-proxy,Attempt:0,}" Oct 8 19:51:37.488549 containerd[1442]: time="2024-10-08T19:51:37.488501031Z" level=info msg="CreateContainer within sandbox \"5d0fb1eb415409816cded87e37d4b02af540b674001fd43f3db0ae4bf91c510c\" for &ContainerMetadata{Name:kube-proxy,Attempt:0,} returns container id \"9d0f67353e7b0447987c564a52bc7a7f7cf8641adc28197b71ba648e0579d157\"" Oct 8 19:51:37.489233 containerd[1442]: time="2024-10-08T19:51:37.489193829Z" level=info msg="StartContainer for \"9d0f67353e7b0447987c564a52bc7a7f7cf8641adc28197b71ba648e0579d157\"" Oct 8 19:51:37.514108 systemd[1]: Started cri-containerd-9d0f67353e7b0447987c564a52bc7a7f7cf8641adc28197b71ba648e0579d157.scope - libcontainer container 9d0f67353e7b0447987c564a52bc7a7f7cf8641adc28197b71ba648e0579d157. Oct 8 19:51:37.534840 containerd[1442]: time="2024-10-08T19:51:37.534788844Z" level=info msg="StartContainer for \"9d0f67353e7b0447987c564a52bc7a7f7cf8641adc28197b71ba648e0579d157\" returns successfully" Oct 8 19:51:37.899387 kubelet[1708]: E1008 19:51:37.899288 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:38.036010 kubelet[1708]: E1008 19:51:38.035971 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:38.045443 kubelet[1708]: I1008 19:51:38.045350 1708 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="kube-system/kube-proxy-v4klm" podStartSLOduration=4.529482566 podStartE2EDuration="7.045302693s" podCreationTimestamp="2024-10-08 19:51:31 +0000 UTC" firstStartedPulling="2024-10-08 19:51:34.955366554 +0000 UTC m=+4.189992273" lastFinishedPulling="2024-10-08 19:51:37.471186721 +0000 UTC m=+6.705812400" observedRunningTime="2024-10-08 19:51:38.045292828 +0000 UTC m=+7.279918546" watchObservedRunningTime="2024-10-08 19:51:38.045302693 +0000 UTC m=+7.279928412" Oct 8 19:51:38.491236 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount3517214273.mount: Deactivated successfully. Oct 8 19:51:38.521158 containerd[1442]: time="2024-10-08T19:51:38.521111298Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel-cni-plugin:v1.1.2\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:38.521728 containerd[1442]: time="2024-10-08T19:51:38.521683469Z" level=info msg="stop pulling image docker.io/flannel/flannel-cni-plugin:v1.1.2: active requests=0, bytes read=3673532" Oct 8 19:51:38.523221 containerd[1442]: time="2024-10-08T19:51:38.523174183Z" level=info msg="ImageCreate event name:\"sha256:b45062ceea496fc421523388cb91166abc7715a15c2e2cbab4e6f8c9d5dc0ab8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:38.525093 containerd[1442]: time="2024-10-08T19:51:38.525064815Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel-cni-plugin@sha256:bf4b62b131666d040f35a327d906ee5a3418280b68a88d9b9c7e828057210443\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:38.526226 containerd[1442]: time="2024-10-08T19:51:38.526189027Z" level=info msg="Pulled image \"docker.io/flannel/flannel-cni-plugin:v1.1.2\" with image id \"sha256:b45062ceea496fc421523388cb91166abc7715a15c2e2cbab4e6f8c9d5dc0ab8\", repo tag \"docker.io/flannel/flannel-cni-plugin:v1.1.2\", repo digest \"docker.io/flannel/flannel-cni-plugin@sha256:bf4b62b131666d040f35a327d906ee5a3418280b68a88d9b9c7e828057210443\", size \"3662650\" in 1.054773499s" Oct 8 19:51:38.526279 containerd[1442]: time="2024-10-08T19:51:38.526224790Z" level=info msg="PullImage \"docker.io/flannel/flannel-cni-plugin:v1.1.2\" returns image reference \"sha256:b45062ceea496fc421523388cb91166abc7715a15c2e2cbab4e6f8c9d5dc0ab8\"" Oct 8 19:51:38.527693 containerd[1442]: time="2024-10-08T19:51:38.527577345Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for container &ContainerMetadata{Name:install-cni-plugin,Attempt:0,}" Oct 8 19:51:38.536458 containerd[1442]: time="2024-10-08T19:51:38.536418279Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for &ContainerMetadata{Name:install-cni-plugin,Attempt:0,} returns container id \"de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a\"" Oct 8 19:51:38.537112 containerd[1442]: time="2024-10-08T19:51:38.536947008Z" level=info msg="StartContainer for \"de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a\"" Oct 8 19:51:38.566158 systemd[1]: Started cri-containerd-de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a.scope - libcontainer container de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a. Oct 8 19:51:38.591066 containerd[1442]: time="2024-10-08T19:51:38.589346886Z" level=info msg="StartContainer for \"de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a\" returns successfully" Oct 8 19:51:38.593664 systemd[1]: cri-containerd-de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a.scope: Deactivated successfully. Oct 8 19:51:38.732591 containerd[1442]: time="2024-10-08T19:51:38.732533177Z" level=info msg="shim disconnected" id=de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a namespace=k8s.io Oct 8 19:51:38.732591 containerd[1442]: time="2024-10-08T19:51:38.732586682Z" level=warning msg="cleaning up after shim disconnected" id=de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a namespace=k8s.io Oct 8 19:51:38.732591 containerd[1442]: time="2024-10-08T19:51:38.732597264Z" level=info msg="cleaning up dead shim" namespace=k8s.io Oct 8 19:51:38.900258 kubelet[1708]: E1008 19:51:38.900145 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:38.960176 systemd[1]: run-containerd-io.containerd.runtime.v2.task-k8s.io-de0fc96afd27ff0a8b10e670866e9ad8d230392ac67af6c5093472bff1a6754a-rootfs.mount: Deactivated successfully. Oct 8 19:51:39.038806 kubelet[1708]: E1008 19:51:39.038662 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:39.038806 kubelet[1708]: E1008 19:51:39.038721 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:39.039642 containerd[1442]: time="2024-10-08T19:51:39.039455314Z" level=info msg="PullImage \"docker.io/flannel/flannel:v0.22.0\"" Oct 8 19:51:39.900952 kubelet[1708]: E1008 19:51:39.900909 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:40.126054 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount3607119400.mount: Deactivated successfully. Oct 8 19:51:40.586916 containerd[1442]: time="2024-10-08T19:51:40.586859646Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel:v0.22.0\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:40.587785 containerd[1442]: time="2024-10-08T19:51:40.587343649Z" level=info msg="stop pulling image docker.io/flannel/flannel:v0.22.0: active requests=0, bytes read=26874261" Oct 8 19:51:40.588651 containerd[1442]: time="2024-10-08T19:51:40.588614898Z" level=info msg="ImageCreate event name:\"sha256:b3d1319ea6da12d4a1dd21a923f6a71f942a7b6e2c4763b8a3cca0725fb8aadf\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:40.593601 containerd[1442]: time="2024-10-08T19:51:40.592740254Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel@sha256:5f83f1243057458e27249157394e3859cf31cc075354af150d497f2ebc8b54db\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:40.593601 containerd[1442]: time="2024-10-08T19:51:40.593485796Z" level=info msg="Pulled image \"docker.io/flannel/flannel:v0.22.0\" with image id \"sha256:b3d1319ea6da12d4a1dd21a923f6a71f942a7b6e2c4763b8a3cca0725fb8aadf\", repo tag \"docker.io/flannel/flannel:v0.22.0\", repo digest \"docker.io/flannel/flannel@sha256:5f83f1243057458e27249157394e3859cf31cc075354af150d497f2ebc8b54db\", size \"26863435\" in 1.55399433s" Oct 8 19:51:40.593601 containerd[1442]: time="2024-10-08T19:51:40.593514276Z" level=info msg="PullImage \"docker.io/flannel/flannel:v0.22.0\" returns image reference \"sha256:b3d1319ea6da12d4a1dd21a923f6a71f942a7b6e2c4763b8a3cca0725fb8aadf\"" Oct 8 19:51:40.595235 containerd[1442]: time="2024-10-08T19:51:40.595202849Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for container &ContainerMetadata{Name:install-cni,Attempt:0,}" Oct 8 19:51:40.604879 containerd[1442]: time="2024-10-08T19:51:40.604837655Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for &ContainerMetadata{Name:install-cni,Attempt:0,} returns container id \"d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547\"" Oct 8 19:51:40.605690 containerd[1442]: time="2024-10-08T19:51:40.605490308Z" level=info msg="StartContainer for \"d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547\"" Oct 8 19:51:40.631135 systemd[1]: Started cri-containerd-d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547.scope - libcontainer container d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547. Oct 8 19:51:40.651500 containerd[1442]: time="2024-10-08T19:51:40.651460099Z" level=info msg="StartContainer for \"d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547\" returns successfully" Oct 8 19:51:40.656868 systemd[1]: cri-containerd-d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547.scope: Deactivated successfully. Oct 8 19:51:40.684672 kubelet[1708]: I1008 19:51:40.684630 1708 kubelet_node_status.go:497] "Fast updating node status as it just became ready" Oct 8 19:51:40.764626 containerd[1442]: time="2024-10-08T19:51:40.764551411Z" level=info msg="shim disconnected" id=d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547 namespace=k8s.io Oct 8 19:51:40.764626 containerd[1442]: time="2024-10-08T19:51:40.764602834Z" level=warning msg="cleaning up after shim disconnected" id=d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547 namespace=k8s.io Oct 8 19:51:40.764626 containerd[1442]: time="2024-10-08T19:51:40.764612115Z" level=info msg="cleaning up dead shim" namespace=k8s.io Oct 8 19:51:40.901322 kubelet[1708]: E1008 19:51:40.901196 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:41.041176 systemd[1]: run-containerd-io.containerd.runtime.v2.task-k8s.io-d475bb0e214382900cd1b6704a2290d06af644b1ce9fc66925e0088e0374f547-rootfs.mount: Deactivated successfully. Oct 8 19:51:41.044787 kubelet[1708]: E1008 19:51:41.044749 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:41.046801 containerd[1442]: time="2024-10-08T19:51:41.046759789Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for container &ContainerMetadata{Name:kube-flannel,Attempt:0,}" Oct 8 19:51:41.061309 containerd[1442]: time="2024-10-08T19:51:41.061266789Z" level=info msg="CreateContainer within sandbox \"4f43428d6ae5213d3fca39f34a772b4b1eaf915827cf63e5a154679f2081bb7f\" for &ContainerMetadata{Name:kube-flannel,Attempt:0,} returns container id \"bc84a286599694174f536af29386526eb94b727dab5a4dd2220a04a0cd32ea21\"" Oct 8 19:51:41.061833 containerd[1442]: time="2024-10-08T19:51:41.061811743Z" level=info msg="StartContainer for \"bc84a286599694174f536af29386526eb94b727dab5a4dd2220a04a0cd32ea21\"" Oct 8 19:51:41.085132 systemd[1]: Started cri-containerd-bc84a286599694174f536af29386526eb94b727dab5a4dd2220a04a0cd32ea21.scope - libcontainer container bc84a286599694174f536af29386526eb94b727dab5a4dd2220a04a0cd32ea21. Oct 8 19:51:41.105870 containerd[1442]: time="2024-10-08T19:51:41.105274079Z" level=info msg="StartContainer for \"bc84a286599694174f536af29386526eb94b727dab5a4dd2220a04a0cd32ea21\" returns successfully" Oct 8 19:51:41.902122 kubelet[1708]: E1008 19:51:41.902076 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:42.048395 kubelet[1708]: E1008 19:51:42.048367 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:42.177562 systemd-networkd[1387]: flannel.1: Link UP Oct 8 19:51:42.177574 systemd-networkd[1387]: flannel.1: Gained carrier Oct 8 19:51:42.902971 kubelet[1708]: E1008 19:51:42.902928 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:43.050063 kubelet[1708]: E1008 19:51:43.050037 1708 dns.go:153] "Nameserver limits exceeded" err="Nameserver limits were exceeded, some nameservers have been omitted, the applied nameserver line is: 1.1.1.1 1.0.0.1 8.8.8.8" Oct 8 19:51:43.586110 systemd-networkd[1387]: flannel.1: Gained IPv6LL Oct 8 19:51:43.904129 kubelet[1708]: E1008 19:51:43.904006 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:44.038281 kubelet[1708]: I1008 19:51:44.038219 1708 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="kube-flannel/kube-flannel-ds-9vcs4" podStartSLOduration=7.409771392 podStartE2EDuration="13.038174504s" podCreationTimestamp="2024-10-08 19:51:31 +0000 UTC" firstStartedPulling="2024-10-08 19:51:34.965456909 +0000 UTC m=+4.200082588" lastFinishedPulling="2024-10-08 19:51:40.593859981 +0000 UTC m=+9.828485700" observedRunningTime="2024-10-08 19:51:42.058496719 +0000 UTC m=+11.293122477" watchObservedRunningTime="2024-10-08 19:51:44.038174504 +0000 UTC m=+13.272800223" Oct 8 19:51:44.038458 kubelet[1708]: I1008 19:51:44.038423 1708 topology_manager.go:215] "Topology Admit Handler" podUID="d1b08439-5079-4144-80d7-90af058e155d" podNamespace="default" podName="nginx-deployment-6d5f899847-dtstv" Oct 8 19:51:44.047062 systemd[1]: Created slice kubepods-besteffort-podd1b08439_5079_4144_80d7_90af058e155d.slice - libcontainer container kubepods-besteffort-podd1b08439_5079_4144_80d7_90af058e155d.slice. Oct 8 19:51:44.074529 kubelet[1708]: I1008 19:51:44.074463 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-zwqwq\" (UniqueName: \"kubernetes.io/projected/d1b08439-5079-4144-80d7-90af058e155d-kube-api-access-zwqwq\") pod \"nginx-deployment-6d5f899847-dtstv\" (UID: \"d1b08439-5079-4144-80d7-90af058e155d\") " pod="default/nginx-deployment-6d5f899847-dtstv" Oct 8 19:51:44.351479 containerd[1442]: time="2024-10-08T19:51:44.351342656Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nginx-deployment-6d5f899847-dtstv,Uid:d1b08439-5079-4144-80d7-90af058e155d,Namespace:default,Attempt:0,}" Oct 8 19:51:44.411475 systemd-networkd[1387]: cni0: Link UP Oct 8 19:51:44.411482 systemd-networkd[1387]: cni0: Gained carrier Oct 8 19:51:44.411729 systemd-networkd[1387]: cni0: Lost carrier Oct 8 19:51:44.417157 systemd-networkd[1387]: vethb4af0a2d: Link UP Oct 8 19:51:44.420590 kernel: cni0: port 1(vethb4af0a2d) entered blocking state Oct 8 19:51:44.420678 kernel: cni0: port 1(vethb4af0a2d) entered disabled state Oct 8 19:51:44.420699 kernel: vethb4af0a2d: entered allmulticast mode Oct 8 19:51:44.420716 kernel: vethb4af0a2d: entered promiscuous mode Oct 8 19:51:44.422541 kernel: cni0: port 1(vethb4af0a2d) entered blocking state Oct 8 19:51:44.422570 kernel: cni0: port 1(vethb4af0a2d) entered forwarding state Oct 8 19:51:44.423426 kernel: cni0: port 1(vethb4af0a2d) entered disabled state Oct 8 19:51:44.434340 kernel: cni0: port 1(vethb4af0a2d) entered blocking state Oct 8 19:51:44.434882 kernel: cni0: port 1(vethb4af0a2d) entered forwarding state Oct 8 19:51:44.434464 systemd-networkd[1387]: vethb4af0a2d: Gained carrier Oct 8 19:51:44.434703 systemd-networkd[1387]: cni0: Gained carrier Oct 8 19:51:44.436273 containerd[1442]: map[string]interface {}{"cniVersion":"0.3.1", "hairpinMode":true, "ipMasq":false, "ipam":map[string]interface {}{"ranges":[][]map[string]interface {}{[]map[string]interface {}{map[string]interface {}{"subnet":"192.168.1.0/24"}}}, "routes":[]types.Route{types.Route{Dst:net.IPNet{IP:net.IP{0xc0, 0xa8, 0x0, 0x0}, Mask:net.IPMask{0xff, 0xff, 0x80, 0x0}}, GW:net.IP(nil)}}, "type":"host-local"}, "isDefaultGateway":true, "isGateway":true, "mtu":(*uint)(0x4000012938), "name":"cbr0", "type":"bridge"} Oct 8 19:51:44.436273 containerd[1442]: delegateAdd: netconf sent to delegate plugin: Oct 8 19:51:44.456663 containerd[1442]: {"cniVersion":"0.3.1","hairpinMode":true,"ipMasq":false,"ipam":{"ranges":[[{"subnet":"192.168.1.0/24"}]],"routes":[{"dst":"192.168.0.0/17"}],"type":"host-local"},"isDefaultGateway":true,"isGateway":true,"mtu":1450,"name":"cbr0","type":"bridge"}time="2024-10-08T19:51:44.456547738Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:51:44.456663 containerd[1442]: time="2024-10-08T19:51:44.456606114Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:51:44.456890 containerd[1442]: time="2024-10-08T19:51:44.456685399Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:44.456890 containerd[1442]: time="2024-10-08T19:51:44.456809892Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:44.484203 systemd[1]: Started cri-containerd-1b596c52e8ab9b5ff8a53bbef58442aa8a2b522319abe4babae0beb65f835d0d.scope - libcontainer container 1b596c52e8ab9b5ff8a53bbef58442aa8a2b522319abe4babae0beb65f835d0d. Oct 8 19:51:44.494519 systemd-resolved[1313]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Oct 8 19:51:44.512564 containerd[1442]: time="2024-10-08T19:51:44.512480217Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nginx-deployment-6d5f899847-dtstv,Uid:d1b08439-5079-4144-80d7-90af058e155d,Namespace:default,Attempt:0,} returns sandbox id \"1b596c52e8ab9b5ff8a53bbef58442aa8a2b522319abe4babae0beb65f835d0d\"" Oct 8 19:51:44.515803 containerd[1442]: time="2024-10-08T19:51:44.515679537Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\"" Oct 8 19:51:44.904737 kubelet[1708]: E1008 19:51:44.904687 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:45.762171 systemd-networkd[1387]: vethb4af0a2d: Gained IPv6LL Oct 8 19:51:45.905827 kubelet[1708]: E1008 19:51:45.905585 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:46.018360 systemd-networkd[1387]: cni0: Gained IPv6LL Oct 8 19:51:46.279630 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount3591837248.mount: Deactivated successfully. Oct 8 19:51:46.906582 kubelet[1708]: E1008 19:51:46.906534 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:46.981549 containerd[1442]: time="2024-10-08T19:51:46.981492734Z" level=info msg="ImageCreate event name:\"ghcr.io/flatcar/nginx:latest\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:46.982710 containerd[1442]: time="2024-10-08T19:51:46.982125542Z" level=info msg="stop pulling image ghcr.io/flatcar/nginx:latest: active requests=0, bytes read=67683126" Oct 8 19:51:46.982938 containerd[1442]: time="2024-10-08T19:51:46.982901040Z" level=info msg="ImageCreate event name:\"sha256:f54f66f995855943802b9f875104327460a71ca1a3e31f6e9b5da90452a195ce\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:46.985579 containerd[1442]: time="2024-10-08T19:51:46.985546455Z" level=info msg="ImageCreate event name:\"ghcr.io/flatcar/nginx@sha256:e833b9da37130a69c1c2ed7b8c61e1f861f75e4804436b3cf81d8463a4e6e5f1\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:46.987532 containerd[1442]: time="2024-10-08T19:51:46.987483684Z" level=info msg="Pulled image \"ghcr.io/flatcar/nginx:latest\" with image id \"sha256:f54f66f995855943802b9f875104327460a71ca1a3e31f6e9b5da90452a195ce\", repo tag \"ghcr.io/flatcar/nginx:latest\", repo digest \"ghcr.io/flatcar/nginx@sha256:e833b9da37130a69c1c2ed7b8c61e1f861f75e4804436b3cf81d8463a4e6e5f1\", size \"67683004\" in 2.471763162s" Oct 8 19:51:46.987532 containerd[1442]: time="2024-10-08T19:51:46.987518538Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\" returns image reference \"sha256:f54f66f995855943802b9f875104327460a71ca1a3e31f6e9b5da90452a195ce\"" Oct 8 19:51:46.988985 containerd[1442]: time="2024-10-08T19:51:46.988945768Z" level=info msg="CreateContainer within sandbox \"1b596c52e8ab9b5ff8a53bbef58442aa8a2b522319abe4babae0beb65f835d0d\" for container &ContainerMetadata{Name:nginx,Attempt:0,}" Oct 8 19:51:46.999238 containerd[1442]: time="2024-10-08T19:51:46.999130534Z" level=info msg="CreateContainer within sandbox \"1b596c52e8ab9b5ff8a53bbef58442aa8a2b522319abe4babae0beb65f835d0d\" for &ContainerMetadata{Name:nginx,Attempt:0,} returns container id \"7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817\"" Oct 8 19:51:46.999836 containerd[1442]: time="2024-10-08T19:51:46.999788414Z" level=info msg="StartContainer for \"7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817\"" Oct 8 19:51:47.027113 systemd[1]: Started cri-containerd-7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817.scope - libcontainer container 7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817. Oct 8 19:51:47.054110 containerd[1442]: time="2024-10-08T19:51:47.053988460Z" level=info msg="StartContainer for \"7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817\" returns successfully" Oct 8 19:51:47.065855 kubelet[1708]: I1008 19:51:47.065823 1708 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="default/nginx-deployment-6d5f899847-dtstv" podStartSLOduration=0.593199556 podStartE2EDuration="3.065774429s" podCreationTimestamp="2024-10-08 19:51:44 +0000 UTC" firstStartedPulling="2024-10-08 19:51:44.515297997 +0000 UTC m=+13.749923716" lastFinishedPulling="2024-10-08 19:51:46.98787287 +0000 UTC m=+16.222498589" observedRunningTime="2024-10-08 19:51:47.065722634 +0000 UTC m=+16.300348353" watchObservedRunningTime="2024-10-08 19:51:47.065774429 +0000 UTC m=+16.300400148" Oct 8 19:51:47.279670 systemd[1]: run-containerd-runc-k8s.io-7c87125e2c41915e3523d60a8bfef1edf212cd2c9b9504f5aae6abc5f373e817-runc.i2aAUm.mount: Deactivated successfully. Oct 8 19:51:47.907256 kubelet[1708]: E1008 19:51:47.907214 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:48.908371 kubelet[1708]: E1008 19:51:48.908319 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:49.909292 kubelet[1708]: E1008 19:51:49.909247 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:50.871936 kubelet[1708]: I1008 19:51:50.871897 1708 topology_manager.go:215] "Topology Admit Handler" podUID="1a2c7477-42b7-4f02-aef6-777ee2036d1a" podNamespace="default" podName="nfs-server-provisioner-0" Oct 8 19:51:50.877604 systemd[1]: Created slice kubepods-besteffort-pod1a2c7477_42b7_4f02_aef6_777ee2036d1a.slice - libcontainer container kubepods-besteffort-pod1a2c7477_42b7_4f02_aef6_777ee2036d1a.slice. Oct 8 19:51:50.909860 kubelet[1708]: E1008 19:51:50.909785 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:50.911973 kubelet[1708]: I1008 19:51:50.911919 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-j9mnt\" (UniqueName: \"kubernetes.io/projected/1a2c7477-42b7-4f02-aef6-777ee2036d1a-kube-api-access-j9mnt\") pod \"nfs-server-provisioner-0\" (UID: \"1a2c7477-42b7-4f02-aef6-777ee2036d1a\") " pod="default/nfs-server-provisioner-0" Oct 8 19:51:50.912166 kubelet[1708]: I1008 19:51:50.912107 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"data\" (UniqueName: \"kubernetes.io/empty-dir/1a2c7477-42b7-4f02-aef6-777ee2036d1a-data\") pod \"nfs-server-provisioner-0\" (UID: \"1a2c7477-42b7-4f02-aef6-777ee2036d1a\") " pod="default/nfs-server-provisioner-0" Oct 8 19:51:51.181481 containerd[1442]: time="2024-10-08T19:51:51.180829796Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nfs-server-provisioner-0,Uid:1a2c7477-42b7-4f02-aef6-777ee2036d1a,Namespace:default,Attempt:0,}" Oct 8 19:51:51.214197 systemd-networkd[1387]: vethfa02488b: Link UP Oct 8 19:51:51.215568 kernel: cni0: port 2(vethfa02488b) entered blocking state Oct 8 19:51:51.215610 kernel: cni0: port 2(vethfa02488b) entered disabled state Oct 8 19:51:51.215627 kernel: vethfa02488b: entered allmulticast mode Oct 8 19:51:51.216977 kernel: vethfa02488b: entered promiscuous mode Oct 8 19:51:51.220994 kernel: cni0: port 2(vethfa02488b) entered blocking state Oct 8 19:51:51.221120 kernel: cni0: port 2(vethfa02488b) entered forwarding state Oct 8 19:51:51.221054 systemd-networkd[1387]: vethfa02488b: Gained carrier Oct 8 19:51:51.225775 containerd[1442]: map[string]interface {}{"cniVersion":"0.3.1", "hairpinMode":true, "ipMasq":false, "ipam":map[string]interface {}{"ranges":[][]map[string]interface {}{[]map[string]interface {}{map[string]interface {}{"subnet":"192.168.1.0/24"}}}, "routes":[]types.Route{types.Route{Dst:net.IPNet{IP:net.IP{0xc0, 0xa8, 0x0, 0x0}, Mask:net.IPMask{0xff, 0xff, 0x80, 0x0}}, GW:net.IP(nil)}}, "type":"host-local"}, "isDefaultGateway":true, "isGateway":true, "mtu":(*uint)(0x4000012928), "name":"cbr0", "type":"bridge"} Oct 8 19:51:51.225775 containerd[1442]: delegateAdd: netconf sent to delegate plugin: Oct 8 19:51:51.239587 containerd[1442]: {"cniVersion":"0.3.1","hairpinMode":true,"ipMasq":false,"ipam":{"ranges":[[{"subnet":"192.168.1.0/24"}]],"routes":[{"dst":"192.168.0.0/17"}],"type":"host-local"},"isDefaultGateway":true,"isGateway":true,"mtu":1450,"name":"cbr0","type":"bridge"}time="2024-10-08T19:51:51.239490064Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:51:51.240219 containerd[1442]: time="2024-10-08T19:51:51.240078736Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:51:51.240219 containerd[1442]: time="2024-10-08T19:51:51.240108028Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:51.240385 containerd[1442]: time="2024-10-08T19:51:51.240203615Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:51:51.270178 systemd[1]: Started cri-containerd-8120e9bba013774915c63a5891e7912d7684c327994090650ce090b398d56b06.scope - libcontainer container 8120e9bba013774915c63a5891e7912d7684c327994090650ce090b398d56b06. Oct 8 19:51:51.279751 systemd-resolved[1313]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Oct 8 19:51:51.294704 containerd[1442]: time="2024-10-08T19:51:51.294666897Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nfs-server-provisioner-0,Uid:1a2c7477-42b7-4f02-aef6-777ee2036d1a,Namespace:default,Attempt:0,} returns sandbox id \"8120e9bba013774915c63a5891e7912d7684c327994090650ce090b398d56b06\"" Oct 8 19:51:51.296112 containerd[1442]: time="2024-10-08T19:51:51.296010360Z" level=info msg="PullImage \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\"" Oct 8 19:51:51.896315 kubelet[1708]: E1008 19:51:51.896271 1708 file.go:104] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:51.910476 kubelet[1708]: E1008 19:51:51.910430 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:52.802091 systemd-networkd[1387]: vethfa02488b: Gained IPv6LL Oct 8 19:51:52.905016 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount1646053639.mount: Deactivated successfully. Oct 8 19:51:52.910892 kubelet[1708]: E1008 19:51:52.910849 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:53.911273 kubelet[1708]: E1008 19:51:53.911225 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:54.214823 containerd[1442]: time="2024-10-08T19:51:54.214682342Z" level=info msg="ImageCreate event name:\"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:54.216711 containerd[1442]: time="2024-10-08T19:51:54.216669936Z" level=info msg="stop pulling image registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8: active requests=0, bytes read=87373625" Oct 8 19:51:54.219564 containerd[1442]: time="2024-10-08T19:51:54.219499346Z" level=info msg="ImageCreate event name:\"sha256:5a42a519e0a8cf95c3c5f18f767c58c8c8b072aaea0a26e5e47a6f206c7df685\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:54.222501 containerd[1442]: time="2024-10-08T19:51:54.222463909Z" level=info msg="ImageCreate event name:\"registry.k8s.io/sig-storage/nfs-provisioner@sha256:c825f3d5e28bde099bd7a3daace28772d412c9157ad47fa752a9ad0baafc118d\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:51:54.223671 containerd[1442]: time="2024-10-08T19:51:54.223533457Z" level=info msg="Pulled image \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\" with image id \"sha256:5a42a519e0a8cf95c3c5f18f767c58c8c8b072aaea0a26e5e47a6f206c7df685\", repo tag \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\", repo digest \"registry.k8s.io/sig-storage/nfs-provisioner@sha256:c825f3d5e28bde099bd7a3daace28772d412c9157ad47fa752a9ad0baafc118d\", size \"87371201\" in 2.927489166s" Oct 8 19:51:54.223671 containerd[1442]: time="2024-10-08T19:51:54.223572352Z" level=info msg="PullImage \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\" returns image reference \"sha256:5a42a519e0a8cf95c3c5f18f767c58c8c8b072aaea0a26e5e47a6f206c7df685\"" Oct 8 19:51:54.225993 containerd[1442]: time="2024-10-08T19:51:54.225900686Z" level=info msg="CreateContainer within sandbox \"8120e9bba013774915c63a5891e7912d7684c327994090650ce090b398d56b06\" for container &ContainerMetadata{Name:nfs-server-provisioner,Attempt:0,}" Oct 8 19:51:54.242687 containerd[1442]: time="2024-10-08T19:51:54.242570704Z" level=info msg="CreateContainer within sandbox \"8120e9bba013774915c63a5891e7912d7684c327994090650ce090b398d56b06\" for &ContainerMetadata{Name:nfs-server-provisioner,Attempt:0,} returns container id \"9f6e9855691877ad72f2799c6015108df14688a45dd619bc69871aff19cb1e2a\"" Oct 8 19:51:54.243225 containerd[1442]: time="2024-10-08T19:51:54.243193341Z" level=info msg="StartContainer for \"9f6e9855691877ad72f2799c6015108df14688a45dd619bc69871aff19cb1e2a\"" Oct 8 19:51:54.275328 systemd[1]: Started cri-containerd-9f6e9855691877ad72f2799c6015108df14688a45dd619bc69871aff19cb1e2a.scope - libcontainer container 9f6e9855691877ad72f2799c6015108df14688a45dd619bc69871aff19cb1e2a. Oct 8 19:51:54.306891 containerd[1442]: time="2024-10-08T19:51:54.306846412Z" level=info msg="StartContainer for \"9f6e9855691877ad72f2799c6015108df14688a45dd619bc69871aff19cb1e2a\" returns successfully" Oct 8 19:51:54.911608 kubelet[1708]: E1008 19:51:54.911558 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:55.912638 kubelet[1708]: E1008 19:51:55.912034 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:56.912375 kubelet[1708]: E1008 19:51:56.912332 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:57.913481 kubelet[1708]: E1008 19:51:57.913428 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:58.914295 kubelet[1708]: E1008 19:51:58.914243 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:51:59.915177 kubelet[1708]: E1008 19:51:59.915135 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:00.915411 kubelet[1708]: E1008 19:52:00.915361 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:01.916809 kubelet[1708]: E1008 19:52:01.915455 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:02.915642 kubelet[1708]: E1008 19:52:02.915581 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:03.701515 kubelet[1708]: I1008 19:52:03.701464 1708 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="default/nfs-server-provisioner-0" podStartSLOduration=10.773340576 podStartE2EDuration="13.701425851s" podCreationTimestamp="2024-10-08 19:51:50 +0000 UTC" firstStartedPulling="2024-10-08 19:51:51.29582398 +0000 UTC m=+20.530449698" lastFinishedPulling="2024-10-08 19:51:54.223909254 +0000 UTC m=+23.458534973" observedRunningTime="2024-10-08 19:51:55.090926613 +0000 UTC m=+24.325552332" watchObservedRunningTime="2024-10-08 19:52:03.701425851 +0000 UTC m=+32.936051570" Oct 8 19:52:03.701898 kubelet[1708]: I1008 19:52:03.701580 1708 topology_manager.go:215] "Topology Admit Handler" podUID="36aa56d5-37de-463c-b357-2b130df3a441" podNamespace="default" podName="test-pod-1" Oct 8 19:52:03.707035 systemd[1]: Created slice kubepods-besteffort-pod36aa56d5_37de_463c_b357_2b130df3a441.slice - libcontainer container kubepods-besteffort-pod36aa56d5_37de_463c_b357_2b130df3a441.slice. Oct 8 19:52:03.889069 kubelet[1708]: I1008 19:52:03.889025 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"pvc-4c5e2517-4323-4312-9f2e-90a8033e5ea6\" (UniqueName: \"kubernetes.io/nfs/36aa56d5-37de-463c-b357-2b130df3a441-pvc-4c5e2517-4323-4312-9f2e-90a8033e5ea6\") pod \"test-pod-1\" (UID: \"36aa56d5-37de-463c-b357-2b130df3a441\") " pod="default/test-pod-1" Oct 8 19:52:03.889069 kubelet[1708]: I1008 19:52:03.889068 1708 reconciler_common.go:258] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-dz6pv\" (UniqueName: \"kubernetes.io/projected/36aa56d5-37de-463c-b357-2b130df3a441-kube-api-access-dz6pv\") pod \"test-pod-1\" (UID: \"36aa56d5-37de-463c-b357-2b130df3a441\") " pod="default/test-pod-1" Oct 8 19:52:03.916476 kubelet[1708]: E1008 19:52:03.916448 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:04.027990 kernel: FS-Cache: Loaded Oct 8 19:52:04.051473 kernel: RPC: Registered named UNIX socket transport module. Oct 8 19:52:04.051578 kernel: RPC: Registered udp transport module. Oct 8 19:52:04.051596 kernel: RPC: Registered tcp transport module. Oct 8 19:52:04.052025 kernel: RPC: Registered tcp-with-tls transport module. Oct 8 19:52:04.053321 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Oct 8 19:52:04.233076 kernel: NFS: Registering the id_resolver key type Oct 8 19:52:04.233224 kernel: Key type id_resolver registered Oct 8 19:52:04.233241 kernel: Key type id_legacy registered Oct 8 19:52:04.260726 nfsidmap[2736]: nss_getpwnam: name 'root@nfs-server-provisioner.default.svc.cluster.local' does not map into domain 'localdomain' Oct 8 19:52:04.267008 nfsidmap[2739]: nss_name_to_gid: name 'root@nfs-server-provisioner.default.svc.cluster.local' does not map into domain 'localdomain' Oct 8 19:52:04.310723 containerd[1442]: time="2024-10-08T19:52:04.310241771Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:test-pod-1,Uid:36aa56d5-37de-463c-b357-2b130df3a441,Namespace:default,Attempt:0,}" Oct 8 19:52:04.336582 systemd-networkd[1387]: veth1ced4d2b: Link UP Oct 8 19:52:04.339442 kernel: cni0: port 3(veth1ced4d2b) entered blocking state Oct 8 19:52:04.339521 kernel: cni0: port 3(veth1ced4d2b) entered disabled state Oct 8 19:52:04.339537 kernel: veth1ced4d2b: entered allmulticast mode Oct 8 19:52:04.339549 kernel: veth1ced4d2b: entered promiscuous mode Oct 8 19:52:04.347889 systemd-networkd[1387]: veth1ced4d2b: Gained carrier Oct 8 19:52:04.348242 kernel: cni0: port 3(veth1ced4d2b) entered blocking state Oct 8 19:52:04.348268 kernel: cni0: port 3(veth1ced4d2b) entered forwarding state Oct 8 19:52:04.350725 containerd[1442]: map[string]interface {}{"cniVersion":"0.3.1", "hairpinMode":true, "ipMasq":false, "ipam":map[string]interface {}{"ranges":[][]map[string]interface {}{[]map[string]interface {}{map[string]interface {}{"subnet":"192.168.1.0/24"}}}, "routes":[]types.Route{types.Route{Dst:net.IPNet{IP:net.IP{0xc0, 0xa8, 0x0, 0x0}, Mask:net.IPMask{0xff, 0xff, 0x80, 0x0}}, GW:net.IP(nil)}}, "type":"host-local"}, "isDefaultGateway":true, "isGateway":true, "mtu":(*uint)(0x4000106628), "name":"cbr0", "type":"bridge"} Oct 8 19:52:04.350725 containerd[1442]: delegateAdd: netconf sent to delegate plugin: Oct 8 19:52:04.370482 containerd[1442]: {"cniVersion":"0.3.1","hairpinMode":true,"ipMasq":false,"ipam":{"ranges":[[{"subnet":"192.168.1.0/24"}]],"routes":[{"dst":"192.168.0.0/17"}],"type":"host-local"},"isDefaultGateway":true,"isGateway":true,"mtu":1450,"name":"cbr0","type":"bridge"}time="2024-10-08T19:52:04.369893429Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:52:04.370482 containerd[1442]: time="2024-10-08T19:52:04.370339884Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:52:04.370482 containerd[1442]: time="2024-10-08T19:52:04.370360247Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:52:04.370482 containerd[1442]: time="2024-10-08T19:52:04.370440457Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:52:04.392156 systemd[1]: Started cri-containerd-dd0fec07456da0cc19d8243089adf03ef32f0f0b0f67e2bcb53f64f7fb2dfd3f.scope - libcontainer container dd0fec07456da0cc19d8243089adf03ef32f0f0b0f67e2bcb53f64f7fb2dfd3f. Oct 8 19:52:04.402330 systemd-resolved[1313]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Oct 8 19:52:04.418013 containerd[1442]: time="2024-10-08T19:52:04.417937691Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:test-pod-1,Uid:36aa56d5-37de-463c-b357-2b130df3a441,Namespace:default,Attempt:0,} returns sandbox id \"dd0fec07456da0cc19d8243089adf03ef32f0f0b0f67e2bcb53f64f7fb2dfd3f\"" Oct 8 19:52:04.419831 containerd[1442]: time="2024-10-08T19:52:04.419623620Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\"" Oct 8 19:52:04.636753 containerd[1442]: time="2024-10-08T19:52:04.636634701Z" level=info msg="ImageUpdate event name:\"ghcr.io/flatcar/nginx:latest\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" Oct 8 19:52:04.637376 containerd[1442]: time="2024-10-08T19:52:04.637314385Z" level=info msg="stop pulling image ghcr.io/flatcar/nginx:latest: active requests=0, bytes read=61" Oct 8 19:52:04.640677 containerd[1442]: time="2024-10-08T19:52:04.640558146Z" level=info msg="Pulled image \"ghcr.io/flatcar/nginx:latest\" with image id \"sha256:f54f66f995855943802b9f875104327460a71ca1a3e31f6e9b5da90452a195ce\", repo tag \"ghcr.io/flatcar/nginx:latest\", repo digest \"ghcr.io/flatcar/nginx@sha256:e833b9da37130a69c1c2ed7b8c61e1f861f75e4804436b3cf81d8463a4e6e5f1\", size \"67683004\" in 220.896882ms" Oct 8 19:52:04.640677 containerd[1442]: time="2024-10-08T19:52:04.640593470Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\" returns image reference \"sha256:f54f66f995855943802b9f875104327460a71ca1a3e31f6e9b5da90452a195ce\"" Oct 8 19:52:04.642055 containerd[1442]: time="2024-10-08T19:52:04.642026488Z" level=info msg="CreateContainer within sandbox \"dd0fec07456da0cc19d8243089adf03ef32f0f0b0f67e2bcb53f64f7fb2dfd3f\" for container &ContainerMetadata{Name:test,Attempt:0,}" Oct 8 19:52:04.656449 containerd[1442]: time="2024-10-08T19:52:04.656328817Z" level=info msg="CreateContainer within sandbox \"dd0fec07456da0cc19d8243089adf03ef32f0f0b0f67e2bcb53f64f7fb2dfd3f\" for &ContainerMetadata{Name:test,Attempt:0,} returns container id \"a9d1bb0beb321b3ef29a4b468507db7b98a4fd5d59afd9af684ddc678fb9ad19\"" Oct 8 19:52:04.657139 containerd[1442]: time="2024-10-08T19:52:04.657071989Z" level=info msg="StartContainer for \"a9d1bb0beb321b3ef29a4b468507db7b98a4fd5d59afd9af684ddc678fb9ad19\"" Oct 8 19:52:04.679133 systemd[1]: Started cri-containerd-a9d1bb0beb321b3ef29a4b468507db7b98a4fd5d59afd9af684ddc678fb9ad19.scope - libcontainer container a9d1bb0beb321b3ef29a4b468507db7b98a4fd5d59afd9af684ddc678fb9ad19. Oct 8 19:52:04.701310 containerd[1442]: time="2024-10-08T19:52:04.701195606Z" level=info msg="StartContainer for \"a9d1bb0beb321b3ef29a4b468507db7b98a4fd5d59afd9af684ddc678fb9ad19\" returns successfully" Oct 8 19:52:04.917080 kubelet[1708]: E1008 19:52:04.916660 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:05.108139 kubelet[1708]: I1008 19:52:05.108103 1708 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="default/test-pod-1" podStartSLOduration=13.88660419 podStartE2EDuration="14.10805446s" podCreationTimestamp="2024-10-08 19:51:51 +0000 UTC" firstStartedPulling="2024-10-08 19:52:04.419353186 +0000 UTC m=+33.653978865" lastFinishedPulling="2024-10-08 19:52:04.640803416 +0000 UTC m=+33.875429135" observedRunningTime="2024-10-08 19:52:05.105405589 +0000 UTC m=+34.340031308" watchObservedRunningTime="2024-10-08 19:52:05.10805446 +0000 UTC m=+34.342680179" Oct 8 19:52:05.917829 kubelet[1708]: E1008 19:52:05.917787 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:06.306147 systemd-networkd[1387]: veth1ced4d2b: Gained IPv6LL Oct 8 19:52:06.918555 kubelet[1708]: E1008 19:52:06.918509 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:07.918825 kubelet[1708]: E1008 19:52:07.918774 1708 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" Oct 8 19:52:08.100584 update_engine[1426]: I20241008 19:52:08.099995 1426 update_attempter.cc:509] Updating boot flags... Oct 8 19:52:08.138994 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 40 scanned by (udev-worker) (2902) Oct 8 19:52:08.171006 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 40 scanned by (udev-worker) (2900) Oct 8 19:52:08.198086 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 40 scanned by (udev-worker) (2900)