May 15 11:58:15.064701 kernel: Booting Linux on physical CPU 0x0000000000 [0x410fd490] May 15 11:58:15.064719 kernel: Linux version 6.12.20-flatcar (build@pony-truck.infra.kinvolk.io) (aarch64-cros-linux-gnu-gcc (Gentoo Hardened 14.2.1_p20241221 p7) 14.2.1 20241221, GNU ld (Gentoo 2.44 p1) 2.44.0) #1 SMP PREEMPT Thu May 15 10:40:40 -00 2025 May 15 11:58:15.064726 kernel: KASLR enabled May 15 11:58:15.064730 kernel: earlycon: pl11 at MMIO 0x00000000effec000 (options '') May 15 11:58:15.064734 kernel: printk: legacy bootconsole [pl11] enabled May 15 11:58:15.064738 kernel: efi: EFI v2.7 by EDK II May 15 11:58:15.064743 kernel: efi: ACPI 2.0=0x3fd5f018 SMBIOS=0x3e580000 SMBIOS 3.0=0x3e560000 MEMATTR=0x3f20f698 RNG=0x3fd5f998 MEMRESERVE=0x3e477598 May 15 11:58:15.064747 kernel: random: crng init done May 15 11:58:15.064751 kernel: secureboot: Secure boot disabled May 15 11:58:15.064755 kernel: ACPI: Early table checksum verification disabled May 15 11:58:15.064758 kernel: ACPI: RSDP 0x000000003FD5F018 000024 (v02 VRTUAL) May 15 11:58:15.064762 kernel: ACPI: XSDT 0x000000003FD5FF18 00006C (v01 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064766 kernel: ACPI: FACP 0x000000003FD5FC18 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064771 kernel: ACPI: DSDT 0x000000003FD41018 01DFCD (v02 MSFTVM DSDT01 00000001 INTL 20230628) May 15 11:58:15.064776 kernel: ACPI: DBG2 0x000000003FD5FB18 000072 (v00 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064780 kernel: ACPI: GTDT 0x000000003FD5FD98 000060 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064784 kernel: ACPI: OEM0 0x000000003FD5F098 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064790 kernel: ACPI: SPCR 0x000000003FD5FA98 000050 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064794 kernel: ACPI: APIC 0x000000003FD5F818 0000FC (v04 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064798 kernel: ACPI: SRAT 0x000000003FD5F198 000234 (v03 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064802 kernel: ACPI: PPTT 0x000000003FD5F418 000120 (v01 VRTUAL MICROSFT 00000000 MSFT 00000000) May 15 11:58:15.064806 kernel: ACPI: BGRT 0x000000003FD5FE98 000038 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001) May 15 11:58:15.064810 kernel: ACPI: SPCR: console: pl011,mmio32,0xeffec000,115200 May 15 11:58:15.064815 kernel: ACPI: Use ACPI SPCR as default console: Yes May 15 11:58:15.064819 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x00000000-0x3fffffff] hotplug May 15 11:58:15.064823 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x100000000-0x1bfffffff] hotplug May 15 11:58:15.064827 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x1c0000000-0xfbfffffff] hotplug May 15 11:58:15.064831 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x1000000000-0xffffffffff] hotplug May 15 11:58:15.064836 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x10000000000-0x1ffffffffff] hotplug May 15 11:58:15.064841 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x20000000000-0x3ffffffffff] hotplug May 15 11:58:15.064845 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x40000000000-0x7ffffffffff] hotplug May 15 11:58:15.064849 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x80000000000-0xfffffffffff] hotplug May 15 11:58:15.064853 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x100000000000-0x1fffffffffff] hotplug May 15 11:58:15.064858 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x200000000000-0x3fffffffffff] hotplug May 15 11:58:15.064862 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x400000000000-0x7fffffffffff] hotplug May 15 11:58:15.064866 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x800000000000-0xffffffffffff] hotplug May 15 11:58:15.064870 kernel: NUMA: Node 0 [mem 0x00000000-0x3fffffff] + [mem 0x100000000-0x1bfffffff] -> [mem 0x00000000-0x1bfffffff] May 15 11:58:15.064875 kernel: NODE_DATA(0) allocated [mem 0x1bf7fddc0-0x1bf804fff] May 15 11:58:15.064879 kernel: Zone ranges: May 15 11:58:15.064883 kernel: DMA [mem 0x0000000000000000-0x00000000ffffffff] May 15 11:58:15.064890 kernel: DMA32 empty May 15 11:58:15.064894 kernel: Normal [mem 0x0000000100000000-0x00000001bfffffff] May 15 11:58:15.064899 kernel: Device empty May 15 11:58:15.064903 kernel: Movable zone start for each node May 15 11:58:15.064908 kernel: Early memory node ranges May 15 11:58:15.064913 kernel: node 0: [mem 0x0000000000000000-0x00000000007fffff] May 15 11:58:15.064917 kernel: node 0: [mem 0x0000000000824000-0x000000003e45ffff] May 15 11:58:15.064921 kernel: node 0: [mem 0x000000003e460000-0x000000003e46ffff] May 15 11:58:15.064926 kernel: node 0: [mem 0x000000003e470000-0x000000003e54ffff] May 15 11:58:15.064930 kernel: node 0: [mem 0x000000003e550000-0x000000003e87ffff] May 15 11:58:15.064934 kernel: node 0: [mem 0x000000003e880000-0x000000003fc7ffff] May 15 11:58:15.064939 kernel: node 0: [mem 0x000000003fc80000-0x000000003fcfffff] May 15 11:58:15.064943 kernel: node 0: [mem 0x000000003fd00000-0x000000003fffffff] May 15 11:58:15.064947 kernel: node 0: [mem 0x0000000100000000-0x00000001bfffffff] May 15 11:58:15.064951 kernel: Initmem setup node 0 [mem 0x0000000000000000-0x00000001bfffffff] May 15 11:58:15.064956 kernel: On node 0, zone DMA: 36 pages in unavailable ranges May 15 11:58:15.064960 kernel: psci: probing for conduit method from ACPI. May 15 11:58:15.064965 kernel: psci: PSCIv1.1 detected in firmware. May 15 11:58:15.064969 kernel: psci: Using standard PSCI v0.2 function IDs May 15 11:58:15.064974 kernel: psci: MIGRATE_INFO_TYPE not supported. May 15 11:58:15.064978 kernel: psci: SMC Calling Convention v1.4 May 15 11:58:15.064982 kernel: ACPI: NUMA: SRAT: PXM 0 -> MPIDR 0x0 -> Node 0 May 15 11:58:15.064986 kernel: ACPI: NUMA: SRAT: PXM 0 -> MPIDR 0x1 -> Node 0 May 15 11:58:15.064991 kernel: percpu: Embedded 33 pages/cpu s98136 r8192 d28840 u135168 May 15 11:58:15.064995 kernel: pcpu-alloc: s98136 r8192 d28840 u135168 alloc=33*4096 May 15 11:58:15.065000 kernel: pcpu-alloc: [0] 0 [0] 1 May 15 11:58:15.065004 kernel: Detected PIPT I-cache on CPU0 May 15 11:58:15.065008 kernel: CPU features: detected: Address authentication (architected QARMA5 algorithm) May 15 11:58:15.065013 kernel: CPU features: detected: GIC system register CPU interface May 15 11:58:15.065018 kernel: CPU features: detected: Spectre-v4 May 15 11:58:15.065022 kernel: CPU features: detected: Spectre-BHB May 15 11:58:15.065026 kernel: CPU features: kernel page table isolation forced ON by KASLR May 15 11:58:15.065031 kernel: CPU features: detected: Kernel page table isolation (KPTI) May 15 11:58:15.065035 kernel: CPU features: detected: ARM erratum 2067961 or 2054223 May 15 11:58:15.065039 kernel: CPU features: detected: SSBS not fully self-synchronizing May 15 11:58:15.065044 kernel: alternatives: applying boot alternatives May 15 11:58:15.065049 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=tty1 console=ttyAMA0,115200n8 earlycon=pl011,0xeffec000 flatcar.first_boot=detected acpi=force flatcar.oem.id=azure flatcar.autologin verity.usrhash=bf509bd8a8efc068ea7b7cbdc99b42bf1cbaf8a0ba93f67c8f1cf632dc3496d8 May 15 11:58:15.065054 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. May 15 11:58:15.065058 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) May 15 11:58:15.065063 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) May 15 11:58:15.065068 kernel: Fallback order for Node 0: 0 May 15 11:58:15.065072 kernel: Built 1 zonelists, mobility grouping on. Total pages: 1048540 May 15 11:58:15.065076 kernel: Policy zone: Normal May 15 11:58:15.065081 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off May 15 11:58:15.065085 kernel: software IO TLB: area num 2. May 15 11:58:15.065089 kernel: software IO TLB: mapped [mem 0x000000003a460000-0x000000003e460000] (64MB) May 15 11:58:15.065094 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1 May 15 11:58:15.065098 kernel: rcu: Preemptible hierarchical RCU implementation. May 15 11:58:15.065103 kernel: rcu: RCU event tracing is enabled. May 15 11:58:15.065108 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=2. May 15 11:58:15.065113 kernel: Trampoline variant of Tasks RCU enabled. May 15 11:58:15.065117 kernel: Tracing variant of Tasks RCU enabled. May 15 11:58:15.065122 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. May 15 11:58:15.065126 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2 May 15 11:58:15.065131 kernel: RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2. May 15 11:58:15.065135 kernel: RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2. May 15 11:58:15.065140 kernel: NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 May 15 11:58:15.065144 kernel: GICv3: 960 SPIs implemented May 15 11:58:15.065148 kernel: GICv3: 0 Extended SPIs implemented May 15 11:58:15.065152 kernel: Root IRQ handler: gic_handle_irq May 15 11:58:15.065157 kernel: GICv3: GICv3 features: 16 PPIs, RSS May 15 11:58:15.065161 kernel: GICv3: GICD_CTRL.DS=0, SCR_EL3.FIQ=0 May 15 11:58:15.065166 kernel: GICv3: CPU0: found redistributor 0 region 0:0x00000000effee000 May 15 11:58:15.065170 kernel: ITS: No ITS available, not enabling LPIs May 15 11:58:15.065175 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. May 15 11:58:15.065179 kernel: arch_timer: cp15 timer(s) running at 1000.00MHz (virt). May 15 11:58:15.065184 kernel: clocksource: arch_sys_counter: mask: 0x1fffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns May 15 11:58:15.065188 kernel: sched_clock: 61 bits at 1000MHz, resolution 1ns, wraps every 4398046511103ns May 15 11:58:15.065193 kernel: Console: colour dummy device 80x25 May 15 11:58:15.065197 kernel: printk: legacy console [tty1] enabled May 15 11:58:15.065202 kernel: ACPI: Core revision 20240827 May 15 11:58:15.065207 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 2000.00 BogoMIPS (lpj=1000000) May 15 11:58:15.065212 kernel: pid_max: default: 32768 minimum: 301 May 15 11:58:15.065216 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,ima May 15 11:58:15.065221 kernel: landlock: Up and running. May 15 11:58:15.065225 kernel: SELinux: Initializing. May 15 11:58:15.065230 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) May 15 11:58:15.065235 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) May 15 11:58:15.065242 kernel: Hyper-V: privilege flags low 0x2e7f, high 0x3b8030, hints 0x1a0000e, misc 0x31e1 May 15 11:58:15.065248 kernel: Hyper-V: Host Build 10.0.26100.1254-1-0 May 15 11:58:15.065253 kernel: Hyper-V: enabling crash_kexec_post_notifiers May 15 11:58:15.065257 kernel: rcu: Hierarchical SRCU implementation. May 15 11:58:15.065262 kernel: rcu: Max phase no-delay instances is 400. May 15 11:58:15.065267 kernel: Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level May 15 11:58:15.065272 kernel: Remapping and enabling EFI services. May 15 11:58:15.065277 kernel: smp: Bringing up secondary CPUs ... May 15 11:58:15.065282 kernel: Detected PIPT I-cache on CPU1 May 15 11:58:15.065286 kernel: GICv3: CPU1: found redistributor 1 region 1:0x00000000f000e000 May 15 11:58:15.065291 kernel: CPU1: Booted secondary processor 0x0000000001 [0x410fd490] May 15 11:58:15.065297 kernel: smp: Brought up 1 node, 2 CPUs May 15 11:58:15.065301 kernel: SMP: Total of 2 processors activated. May 15 11:58:15.065306 kernel: CPU: All CPU(s) started at EL1 May 15 11:58:15.065311 kernel: CPU features: detected: 32-bit EL0 Support May 15 11:58:15.065316 kernel: CPU features: detected: Instruction cache invalidation not required for I/D coherence May 15 11:58:15.065321 kernel: CPU features: detected: Data cache clean to the PoU not required for I/D coherence May 15 11:58:15.065325 kernel: CPU features: detected: Common not Private translations May 15 11:58:15.065330 kernel: CPU features: detected: CRC32 instructions May 15 11:58:15.065335 kernel: CPU features: detected: Generic authentication (architected QARMA5 algorithm) May 15 11:58:15.065340 kernel: CPU features: detected: RCpc load-acquire (LDAPR) May 15 11:58:15.065345 kernel: CPU features: detected: LSE atomic instructions May 15 11:58:15.065350 kernel: CPU features: detected: Privileged Access Never May 15 11:58:15.065355 kernel: CPU features: detected: Speculation barrier (SB) May 15 11:58:15.065359 kernel: CPU features: detected: TLB range maintenance instructions May 15 11:58:15.065364 kernel: CPU features: detected: Speculative Store Bypassing Safe (SSBS) May 15 11:58:15.065369 kernel: CPU features: detected: Scalable Vector Extension May 15 11:58:15.065373 kernel: alternatives: applying system-wide alternatives May 15 11:58:15.065378 kernel: CPU features: detected: Hardware dirty bit management on CPU0-1 May 15 11:58:15.065384 kernel: SVE: maximum available vector length 16 bytes per vector May 15 11:58:15.065388 kernel: SVE: default vector length 16 bytes per vector May 15 11:58:15.065393 kernel: Memory: 3976108K/4194160K available (11072K kernel code, 2276K rwdata, 8928K rodata, 39424K init, 1034K bss, 213432K reserved, 0K cma-reserved) May 15 11:58:15.065398 kernel: devtmpfs: initialized May 15 11:58:15.065403 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns May 15 11:58:15.065408 kernel: futex hash table entries: 512 (order: 3, 32768 bytes, linear) May 15 11:58:15.065412 kernel: 2G module region forced by RANDOMIZE_MODULE_REGION_FULL May 15 11:58:15.065417 kernel: 0 pages in range for non-PLT usage May 15 11:58:15.065422 kernel: 508544 pages in range for PLT usage May 15 11:58:15.065427 kernel: pinctrl core: initialized pinctrl subsystem May 15 11:58:15.065432 kernel: SMBIOS 3.1.0 present. May 15 11:58:15.065451 kernel: DMI: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 09/28/2024 May 15 11:58:15.065456 kernel: DMI: Memory slots populated: 2/2 May 15 11:58:15.065461 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family May 15 11:58:15.065465 kernel: DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations May 15 11:58:15.065470 kernel: DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations May 15 11:58:15.065475 kernel: DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations May 15 11:58:15.065480 kernel: audit: initializing netlink subsys (disabled) May 15 11:58:15.065486 kernel: audit: type=2000 audit(0.066:1): state=initialized audit_enabled=0 res=1 May 15 11:58:15.065490 kernel: thermal_sys: Registered thermal governor 'step_wise' May 15 11:58:15.065495 kernel: cpuidle: using governor menu May 15 11:58:15.065500 kernel: hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. May 15 11:58:15.065505 kernel: ASID allocator initialised with 32768 entries May 15 11:58:15.065509 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 May 15 11:58:15.065514 kernel: Serial: AMBA PL011 UART driver May 15 11:58:15.065519 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages May 15 11:58:15.065523 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page May 15 11:58:15.065529 kernel: HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages May 15 11:58:15.065534 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page May 15 11:58:15.065538 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages May 15 11:58:15.065543 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page May 15 11:58:15.065548 kernel: HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages May 15 11:58:15.065552 kernel: HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page May 15 11:58:15.065557 kernel: ACPI: Added _OSI(Module Device) May 15 11:58:15.065561 kernel: ACPI: Added _OSI(Processor Device) May 15 11:58:15.065566 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) May 15 11:58:15.065572 kernel: ACPI: Added _OSI(Processor Aggregator Device) May 15 11:58:15.065576 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded May 15 11:58:15.065581 kernel: ACPI: Interpreter enabled May 15 11:58:15.065586 kernel: ACPI: Using GIC for interrupt routing May 15 11:58:15.065590 kernel: ARMH0011:00: ttyAMA0 at MMIO 0xeffec000 (irq = 12, base_baud = 0) is a SBSA May 15 11:58:15.065595 kernel: printk: legacy console [ttyAMA0] enabled May 15 11:58:15.065600 kernel: printk: legacy bootconsole [pl11] disabled May 15 11:58:15.065604 kernel: ARMH0011:01: ttyAMA1 at MMIO 0xeffeb000 (irq = 13, base_baud = 0) is a SBSA May 15 11:58:15.065609 kernel: ACPI: CPU0 has been hot-added May 15 11:58:15.065615 kernel: ACPI: CPU1 has been hot-added May 15 11:58:15.065620 kernel: iommu: Default domain type: Translated May 15 11:58:15.065624 kernel: iommu: DMA domain TLB invalidation policy: strict mode May 15 11:58:15.065629 kernel: efivars: Registered efivars operations May 15 11:58:15.065634 kernel: vgaarb: loaded May 15 11:58:15.065638 kernel: clocksource: Switched to clocksource arch_sys_counter May 15 11:58:15.065643 kernel: VFS: Disk quotas dquot_6.6.0 May 15 11:58:15.065648 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) May 15 11:58:15.065652 kernel: pnp: PnP ACPI init May 15 11:58:15.065658 kernel: pnp: PnP ACPI: found 0 devices May 15 11:58:15.065662 kernel: NET: Registered PF_INET protocol family May 15 11:58:15.065667 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) May 15 11:58:15.065672 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) May 15 11:58:15.065677 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) May 15 11:58:15.065682 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) May 15 11:58:15.065686 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) May 15 11:58:15.065691 kernel: TCP: Hash tables configured (established 32768 bind 32768) May 15 11:58:15.065696 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) May 15 11:58:15.065702 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) May 15 11:58:15.065706 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family May 15 11:58:15.065711 kernel: PCI: CLS 0 bytes, default 64 May 15 11:58:15.065715 kernel: kvm [1]: HYP mode not available May 15 11:58:15.065720 kernel: Initialise system trusted keyrings May 15 11:58:15.065725 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 May 15 11:58:15.065729 kernel: Key type asymmetric registered May 15 11:58:15.065734 kernel: Asymmetric key parser 'x509' registered May 15 11:58:15.065739 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) May 15 11:58:15.065744 kernel: io scheduler mq-deadline registered May 15 11:58:15.065749 kernel: io scheduler kyber registered May 15 11:58:15.065754 kernel: io scheduler bfq registered May 15 11:58:15.065759 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled May 15 11:58:15.065763 kernel: thunder_xcv, ver 1.0 May 15 11:58:15.065768 kernel: thunder_bgx, ver 1.0 May 15 11:58:15.065772 kernel: nicpf, ver 1.0 May 15 11:58:15.065777 kernel: nicvf, ver 1.0 May 15 11:58:15.065882 kernel: rtc-efi rtc-efi.0: registered as rtc0 May 15 11:58:15.068518 kernel: rtc-efi rtc-efi.0: setting system clock to 2025-05-15T11:58:14 UTC (1747310294) May 15 11:58:15.068536 kernel: efifb: probing for efifb May 15 11:58:15.068542 kernel: efifb: framebuffer at 0x40000000, using 3072k, total 3072k May 15 11:58:15.068548 kernel: efifb: mode is 1024x768x32, linelength=4096, pages=1 May 15 11:58:15.068553 kernel: efifb: scrolling: redraw May 15 11:58:15.068558 kernel: efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0 May 15 11:58:15.068563 kernel: Console: switching to colour frame buffer device 128x48 May 15 11:58:15.068567 kernel: fb0: EFI VGA frame buffer device May 15 11:58:15.068576 kernel: SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping .... May 15 11:58:15.068581 kernel: hid: raw HID events driver (C) Jiri Kosina May 15 11:58:15.068586 kernel: hw perfevents: enabled with armv8_pmuv3_0 PMU driver, 7 (0,8000003f) counters available May 15 11:58:15.068591 kernel: watchdog: NMI not fully supported May 15 11:58:15.068596 kernel: watchdog: Hard watchdog permanently disabled May 15 11:58:15.068601 kernel: NET: Registered PF_INET6 protocol family May 15 11:58:15.068605 kernel: Segment Routing with IPv6 May 15 11:58:15.068610 kernel: In-situ OAM (IOAM) with IPv6 May 15 11:58:15.068615 kernel: NET: Registered PF_PACKET protocol family May 15 11:58:15.068621 kernel: Key type dns_resolver registered May 15 11:58:15.068626 kernel: registered taskstats version 1 May 15 11:58:15.068630 kernel: Loading compiled-in X.509 certificates May 15 11:58:15.068635 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.12.20-flatcar: 6c8c7c40bf8565fead88558d446d0157ca21f08d' May 15 11:58:15.068640 kernel: Demotion targets for Node 0: null May 15 11:58:15.068645 kernel: Key type .fscrypt registered May 15 11:58:15.068650 kernel: Key type fscrypt-provisioning registered May 15 11:58:15.068654 kernel: ima: No TPM chip found, activating TPM-bypass! May 15 11:58:15.068659 kernel: ima: Allocated hash algorithm: sha1 May 15 11:58:15.068665 kernel: ima: No architecture policies found May 15 11:58:15.068670 kernel: alg: No test for fips(ansi_cprng) (fips_ansi_cprng) May 15 11:58:15.068674 kernel: clk: Disabling unused clocks May 15 11:58:15.068679 kernel: PM: genpd: Disabling unused power domains May 15 11:58:15.068684 kernel: Warning: unable to open an initial console. May 15 11:58:15.068689 kernel: Freeing unused kernel memory: 39424K May 15 11:58:15.068693 kernel: Run /init as init process May 15 11:58:15.068698 kernel: with arguments: May 15 11:58:15.068703 kernel: /init May 15 11:58:15.068709 kernel: with environment: May 15 11:58:15.068713 kernel: HOME=/ May 15 11:58:15.068718 kernel: TERM=linux May 15 11:58:15.068723 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a May 15 11:58:15.068728 systemd[1]: Successfully made /usr/ read-only. May 15 11:58:15.068735 systemd[1]: systemd 256.8 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP -GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) May 15 11:58:15.068741 systemd[1]: Detected virtualization microsoft. May 15 11:58:15.068746 systemd[1]: Detected architecture arm64. May 15 11:58:15.068751 systemd[1]: Running in initrd. May 15 11:58:15.068756 systemd[1]: No hostname configured, using default hostname. May 15 11:58:15.068761 systemd[1]: Hostname set to . May 15 11:58:15.068766 systemd[1]: Initializing machine ID from random generator. May 15 11:58:15.068772 systemd[1]: Queued start job for default target initrd.target. May 15 11:58:15.068777 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. May 15 11:58:15.068782 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. May 15 11:58:15.068789 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... May 15 11:58:15.068794 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... May 15 11:58:15.068799 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... May 15 11:58:15.068805 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... May 15 11:58:15.068811 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... May 15 11:58:15.068816 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... May 15 11:58:15.068821 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). May 15 11:58:15.068828 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. May 15 11:58:15.068833 systemd[1]: Reached target paths.target - Path Units. May 15 11:58:15.068838 systemd[1]: Reached target slices.target - Slice Units. May 15 11:58:15.068843 systemd[1]: Reached target swap.target - Swaps. May 15 11:58:15.068848 systemd[1]: Reached target timers.target - Timer Units. May 15 11:58:15.068853 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. May 15 11:58:15.068858 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. May 15 11:58:15.068863 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). May 15 11:58:15.068868 systemd[1]: Listening on systemd-journald.socket - Journal Sockets. May 15 11:58:15.068874 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. May 15 11:58:15.068880 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. May 15 11:58:15.068885 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. May 15 11:58:15.068890 systemd[1]: Reached target sockets.target - Socket Units. May 15 11:58:15.068895 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... May 15 11:58:15.068900 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... May 15 11:58:15.068905 systemd[1]: Finished network-cleanup.service - Network Cleanup. May 15 11:58:15.068910 systemd[1]: systemd-battery-check.service - Check battery level during early boot was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/class/power_supply). May 15 11:58:15.068917 systemd[1]: Starting systemd-fsck-usr.service... May 15 11:58:15.068922 systemd[1]: Starting systemd-journald.service - Journal Service... May 15 11:58:15.068927 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... May 15 11:58:15.068945 systemd-journald[225]: Collecting audit messages is disabled. May 15 11:58:15.068959 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... May 15 11:58:15.068966 systemd-journald[225]: Journal started May 15 11:58:15.068980 systemd-journald[225]: Runtime Journal (/run/log/journal/306cb487ddda4da5b1c9fd3d0e1baa43) is 8M, max 78.5M, 70.5M free. May 15 11:58:15.072927 systemd-modules-load[227]: Inserted module 'overlay' May 15 11:58:15.092774 systemd[1]: Started systemd-journald.service - Journal Service. May 15 11:58:15.092804 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. May 15 11:58:15.101464 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. May 15 11:58:15.110559 kernel: Bridge firewalling registered May 15 11:58:15.109764 systemd-modules-load[227]: Inserted module 'br_netfilter' May 15 11:58:15.118740 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. May 15 11:58:15.132877 systemd[1]: Finished systemd-fsck-usr.service. May 15 11:58:15.136852 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. May 15 11:58:15.145996 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:15.158316 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... May 15 11:58:15.175884 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... May 15 11:58:15.185105 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... May 15 11:58:15.205668 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... May 15 11:58:15.217883 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. May 15 11:58:15.224330 systemd-tmpfiles[256]: /usr/lib/tmpfiles.d/var.conf:14: Duplicate line for path "/var/log", ignoring. May 15 11:58:15.230587 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. May 15 11:58:15.235889 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. May 15 11:58:15.248752 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. May 15 11:58:15.260800 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... May 15 11:58:15.287139 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... May 15 11:58:15.297948 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... May 15 11:58:15.316876 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. May 15 11:58:15.331228 dracut-cmdline[263]: Using kernel command line parameters: rd.driver.pre=btrfs SYSTEMD_SULOGIN_FORCE=1 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=tty1 console=ttyAMA0,115200n8 earlycon=pl011,0xeffec000 flatcar.first_boot=detected acpi=force flatcar.oem.id=azure flatcar.autologin verity.usrhash=bf509bd8a8efc068ea7b7cbdc99b42bf1cbaf8a0ba93f67c8f1cf632dc3496d8 May 15 11:58:15.367200 systemd-resolved[264]: Positive Trust Anchors: May 15 11:58:15.367215 systemd-resolved[264]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d May 15 11:58:15.367235 systemd-resolved[264]: 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 May 15 11:58:15.369305 systemd-resolved[264]: Defaulting to hostname 'linux'. May 15 11:58:15.370893 systemd[1]: Started systemd-resolved.service - Network Name Resolution. May 15 11:58:15.377071 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. May 15 11:58:15.481445 kernel: SCSI subsystem initialized May 15 11:58:15.486455 kernel: Loading iSCSI transport class v2.0-870. May 15 11:58:15.494454 kernel: iscsi: registered transport (tcp) May 15 11:58:15.507721 kernel: iscsi: registered transport (qla4xxx) May 15 11:58:15.507756 kernel: QLogic iSCSI HBA Driver May 15 11:58:15.520663 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... May 15 11:58:15.543585 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. May 15 11:58:15.557032 systemd[1]: Reached target network-pre.target - Preparation for Network. May 15 11:58:15.601261 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. May 15 11:58:15.606711 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... May 15 11:58:15.676455 kernel: raid6: neonx8 gen() 18534 MB/s May 15 11:58:15.694471 kernel: raid6: neonx4 gen() 18563 MB/s May 15 11:58:15.713454 kernel: raid6: neonx2 gen() 17087 MB/s May 15 11:58:15.733469 kernel: raid6: neonx1 gen() 15013 MB/s May 15 11:58:15.752528 kernel: raid6: int64x8 gen() 10551 MB/s May 15 11:58:15.771539 kernel: raid6: int64x4 gen() 10615 MB/s May 15 11:58:15.791462 kernel: raid6: int64x2 gen() 8975 MB/s May 15 11:58:15.813317 kernel: raid6: int64x1 gen() 7000 MB/s May 15 11:58:15.813326 kernel: raid6: using algorithm neonx4 gen() 18563 MB/s May 15 11:58:15.841027 kernel: raid6: .... xor() 15147 MB/s, rmw enabled May 15 11:58:15.841036 kernel: raid6: using neon recovery algorithm May 15 11:58:15.851345 kernel: xor: measuring software checksum speed May 15 11:58:15.851405 kernel: 8regs : 28595 MB/sec May 15 11:58:15.854577 kernel: 32regs : 28789 MB/sec May 15 11:58:15.857797 kernel: arm64_neon : 37614 MB/sec May 15 11:58:15.861387 kernel: xor: using function: arm64_neon (37614 MB/sec) May 15 11:58:15.900460 kernel: Btrfs loaded, zoned=no, fsverity=no May 15 11:58:15.906473 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. May 15 11:58:15.918472 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... May 15 11:58:15.950039 systemd-udevd[475]: Using default interface naming scheme 'v255'. May 15 11:58:15.954378 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. May 15 11:58:15.961521 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... May 15 11:58:15.985939 dracut-pre-trigger[484]: rd.md=0: removing MD RAID activation May 15 11:58:16.005933 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. May 15 11:58:16.016010 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... May 15 11:58:16.057455 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. May 15 11:58:16.069521 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... May 15 11:58:16.131465 kernel: hv_vmbus: Vmbus version:5.3 May 15 11:58:16.139344 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. May 15 11:58:16.139472 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:16.174977 kernel: hv_vmbus: registering driver hyperv_keyboard May 15 11:58:16.174995 kernel: hv_vmbus: registering driver hid_hyperv May 15 11:58:16.175003 kernel: input: AT Translated Set 2 keyboard as /devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/MSFT1000:00/d34b2567-b9b6-42b9-8778-0a4ec0b955bf/serio0/input/input0 May 15 11:58:16.175019 kernel: pps_core: LinuxPPS API ver. 1 registered May 15 11:58:16.175025 kernel: hv_vmbus: registering driver hv_storvsc May 15 11:58:16.167839 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... May 15 11:58:16.190520 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti May 15 11:58:16.179987 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... May 15 11:58:16.214233 kernel: input: Microsoft Vmbus HID-compliant Mouse as /devices/0006:045E:0621.0001/input/input1 May 15 11:58:16.214252 kernel: hid-hyperv 0006:045E:0621.0001: input: VIRTUAL HID v0.01 Mouse [Microsoft Vmbus HID-compliant Mouse] on May 15 11:58:16.214388 kernel: hv_vmbus: registering driver hv_netvsc May 15 11:58:16.207121 systemd[1]: run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Deactivated successfully. May 15 11:58:16.226238 kernel: scsi host1: storvsc_host_t May 15 11:58:16.226386 kernel: scsi host0: storvsc_host_t May 15 11:58:16.224554 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. May 15 11:58:16.249949 kernel: scsi 0:0:0:0: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5 May 15 11:58:16.254913 kernel: scsi 0:0:0:2: CD-ROM Msft Virtual DVD-ROM 1.0 PQ: 0 ANSI: 5 May 15 11:58:16.224631 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:16.243346 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... May 15 11:58:16.272467 kernel: PTP clock support registered May 15 11:58:16.289910 kernel: hv_utils: Registering HyperV Utility Driver May 15 11:58:16.289939 kernel: hv_vmbus: registering driver hv_utils May 15 11:58:16.289947 kernel: hv_utils: Heartbeat IC version 3.0 May 15 11:58:16.289953 kernel: hv_utils: Shutdown IC version 3.2 May 15 11:58:16.289959 kernel: hv_utils: TimeSync IC version 4.0 May 15 11:58:16.290450 kernel: sd 0:0:0:0: [sda] 63737856 512-byte logical blocks: (32.6 GB/30.4 GiB) May 15 11:58:16.533839 kernel: sd 0:0:0:0: [sda] 4096-byte physical blocks May 15 11:58:16.533924 kernel: sd 0:0:0:0: [sda] Write Protect is off May 15 11:58:16.533989 kernel: sd 0:0:0:0: [sda] Mode Sense: 0f 00 10 00 May 15 11:58:16.534048 kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, supports DPO and FUA May 15 11:58:16.534108 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#195 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001 May 15 11:58:16.534177 kernel: hv_netvsc 00224876-fffc-0022-4876-fffc00224876 eth0: VF slot 1 added May 15 11:58:16.534231 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#202 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001 May 15 11:58:16.534281 kernel: sda: sda1 sda2 sda3 sda4 sda6 sda7 sda9 May 15 11:58:16.534288 kernel: sd 0:0:0:0: [sda] Attached SCSI disk May 15 11:58:16.479886 systemd-resolved[264]: Clock change detected. Flushing caches. May 15 11:58:16.540923 kernel: hv_vmbus: registering driver hv_pci May 15 11:58:16.489904 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:16.550766 kernel: hv_pci 016e4e8f-5720-4a79-937d-b217d2e0b447: PCI VMBus probing: Using version 0x10004 May 15 11:58:16.615946 kernel: sr 0:0:0:2: [sr0] scsi-1 drive May 15 11:58:16.616083 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 May 15 11:58:16.616100 kernel: sr 0:0:0:2: Attached scsi CD-ROM sr0 May 15 11:58:16.616165 kernel: hv_pci 016e4e8f-5720-4a79-937d-b217d2e0b447: PCI host bridge to bus 5720:00 May 15 11:58:16.616224 kernel: pci_bus 5720:00: root bus resource [mem 0xfc0000000-0xfc00fffff window] May 15 11:58:16.616303 kernel: pci_bus 5720:00: No busn resource found for root bus, will use [bus 00-ff] May 15 11:58:16.616356 kernel: pci 5720:00:02.0: [15b3:101a] type 00 class 0x020000 PCIe Endpoint May 15 11:58:16.616423 kernel: pci 5720:00:02.0: BAR 0 [mem 0xfc0000000-0xfc00fffff 64bit pref] May 15 11:58:16.616482 kernel: pci 5720:00:02.0: enabling Extended Tags May 15 11:58:16.616539 kernel: pci 5720:00:02.0: 0.000 Gb/s available PCIe bandwidth, limited by Unknown x0 link at 5720:00:02.0 (capable of 252.048 Gb/s with 16.0 GT/s PCIe x16 link) May 15 11:58:16.616608 kernel: pci_bus 5720:00: busn_res: [bus 00-ff] end is updated to 00 May 15 11:58:16.617194 kernel: pci 5720:00:02.0: BAR 0 [mem 0xfc0000000-0xfc00fffff 64bit pref]: assigned May 15 11:58:16.636622 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#275 cmd 0x85 status: scsi 0x2 srb 0x6 hv 0xc0000001 May 15 11:58:16.656610 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#312 cmd 0x85 status: scsi 0x2 srb 0x6 hv 0xc0000001 May 15 11:58:16.697565 kernel: mlx5_core 5720:00:02.0: enabling device (0000 -> 0002) May 15 11:58:16.889094 kernel: mlx5_core 5720:00:02.0: PTM is not supported by PCIe May 15 11:58:16.889217 kernel: mlx5_core 5720:00:02.0: firmware version: 16.30.5006 May 15 11:58:16.889285 kernel: hv_netvsc 00224876-fffc-0022-4876-fffc00224876 eth0: VF registering: eth1 May 15 11:58:16.889354 kernel: mlx5_core 5720:00:02.0 eth1: joined to eth0 May 15 11:58:16.889675 kernel: mlx5_core 5720:00:02.0: MLX5E: StrdRq(1) RqSz(8) StrdSz(2048) RxCqeCmprss(0 basic) May 15 11:58:16.895612 kernel: mlx5_core 5720:00:02.0 enP22304s1: renamed from eth1 May 15 11:58:17.146498 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - Virtual_Disk OEM. May 15 11:58:17.164274 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - Virtual_Disk EFI-SYSTEM. May 15 11:58:17.179667 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - Virtual_Disk USR-A. May 15 11:58:17.184432 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - Virtual_Disk USR-A. May 15 11:58:17.197357 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... May 15 11:58:17.293256 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - Virtual_Disk ROOT. May 15 11:58:17.400737 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. May 15 11:58:17.405608 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. May 15 11:58:17.413757 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. May 15 11:58:17.422834 systemd[1]: Reached target remote-fs.target - Remote File Systems. May 15 11:58:17.431768 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... May 15 11:58:17.457364 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. May 15 11:58:18.232634 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#312 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001 May 15 11:58:18.244909 kernel: sda: sda1 sda2 sda3 sda4 sda6 sda7 sda9 May 15 11:58:18.245171 disk-uuid[640]: The operation has completed successfully. May 15 11:58:18.308019 systemd[1]: disk-uuid.service: Deactivated successfully. May 15 11:58:18.308116 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. May 15 11:58:18.335455 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... May 15 11:58:18.351587 sh[817]: Success May 15 11:58:18.384447 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. May 15 11:58:18.384487 kernel: device-mapper: uevent: version 1.0.3 May 15 11:58:18.389259 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev May 15 11:58:18.399617 kernel: device-mapper: verity: sha256 using shash "sha256-ce" May 15 11:58:18.598413 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. May 15 11:58:18.606309 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... May 15 11:58:18.617569 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. May 15 11:58:18.634611 kernel: BTRFS info: 'norecovery' is for compatibility only, recommended to use 'rescue=nologreplay' May 15 11:58:18.639658 kernel: BTRFS: device fsid 0a747134-9b18-4ef1-ad11-5025524c86c8 devid 1 transid 40 /dev/mapper/usr (254:0) scanned by mount (835) May 15 11:58:18.646122 kernel: BTRFS info (device dm-0): first mount of filesystem 0a747134-9b18-4ef1-ad11-5025524c86c8 May 15 11:58:18.650645 kernel: BTRFS info (device dm-0): using crc32c (crc32c-generic) checksum algorithm May 15 11:58:18.653695 kernel: BTRFS info (device dm-0): using free-space-tree May 15 11:58:18.955169 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. May 15 11:58:18.959170 systemd[1]: Reached target initrd-usr-fs.target - Initrd /usr File System. May 15 11:58:18.966724 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. May 15 11:58:18.967393 systemd[1]: Starting ignition-setup.service - Ignition (setup)... May 15 11:58:18.988238 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... May 15 11:58:19.016439 kernel: BTRFS: device label OEM devid 1 transid 15 /dev/sda6 (8:6) scanned by mount (874) May 15 11:58:19.016480 kernel: BTRFS info (device sda6): first mount of filesystem 3936141b-01f3-466e-a92a-4f7ff09b25a9 May 15 11:58:19.016488 kernel: BTRFS info (device sda6): using crc32c (crc32c-generic) checksum algorithm May 15 11:58:19.023570 kernel: BTRFS info (device sda6): using free-space-tree May 15 11:58:19.058811 kernel: BTRFS info (device sda6): last unmount of filesystem 3936141b-01f3-466e-a92a-4f7ff09b25a9 May 15 11:58:19.059945 systemd[1]: Finished ignition-setup.service - Ignition (setup). May 15 11:58:19.068451 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... May 15 11:58:19.093861 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. May 15 11:58:19.104912 systemd[1]: Starting systemd-networkd.service - Network Configuration... May 15 11:58:19.145963 systemd-networkd[1004]: lo: Link UP May 15 11:58:19.145971 systemd-networkd[1004]: lo: Gained carrier May 15 11:58:19.147577 systemd-networkd[1004]: Enumeration completed May 15 11:58:19.148525 systemd[1]: Started systemd-networkd.service - Network Configuration. May 15 11:58:19.148825 systemd-networkd[1004]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. May 15 11:58:19.148828 systemd-networkd[1004]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. May 15 11:58:19.156172 systemd[1]: Reached target network.target - Network. May 15 11:58:19.204609 kernel: mlx5_core 5720:00:02.0 enP22304s1: Link up May 15 11:58:19.237898 kernel: hv_netvsc 00224876-fffc-0022-4876-fffc00224876 eth0: Data path switched to VF: enP22304s1 May 15 11:58:19.237656 systemd-networkd[1004]: enP22304s1: Link UP May 15 11:58:19.237709 systemd-networkd[1004]: eth0: Link UP May 15 11:58:19.237794 systemd-networkd[1004]: eth0: Gained carrier May 15 11:58:19.237802 systemd-networkd[1004]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. May 15 11:58:19.256270 systemd-networkd[1004]: enP22304s1: Gained carrier May 15 11:58:19.266632 systemd-networkd[1004]: eth0: DHCPv4 address 10.200.20.25/24, gateway 10.200.20.1 acquired from 168.63.129.16 May 15 11:58:20.303288 ignition[977]: Ignition 2.21.0 May 15 11:58:20.303301 ignition[977]: Stage: fetch-offline May 15 11:58:20.306911 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). May 15 11:58:20.303374 ignition[977]: no configs at "/usr/lib/ignition/base.d" May 15 11:58:20.314937 systemd[1]: Starting ignition-fetch.service - Ignition (fetch)... May 15 11:58:20.303380 ignition[977]: no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:20.303477 ignition[977]: parsed url from cmdline: "" May 15 11:58:20.303479 ignition[977]: no config URL provided May 15 11:58:20.303482 ignition[977]: reading system config file "/usr/lib/ignition/user.ign" May 15 11:58:20.303487 ignition[977]: no config at "/usr/lib/ignition/user.ign" May 15 11:58:20.303490 ignition[977]: failed to fetch config: resource requires networking May 15 11:58:20.303722 ignition[977]: Ignition finished successfully May 15 11:58:20.344858 ignition[1013]: Ignition 2.21.0 May 15 11:58:20.344863 ignition[1013]: Stage: fetch May 15 11:58:20.345196 ignition[1013]: no configs at "/usr/lib/ignition/base.d" May 15 11:58:20.345204 ignition[1013]: no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:20.345530 ignition[1013]: parsed url from cmdline: "" May 15 11:58:20.345535 ignition[1013]: no config URL provided May 15 11:58:20.345541 ignition[1013]: reading system config file "/usr/lib/ignition/user.ign" May 15 11:58:20.345555 ignition[1013]: no config at "/usr/lib/ignition/user.ign" May 15 11:58:20.345579 ignition[1013]: GET http://169.254.169.254/metadata/instance/compute/userData?api-version=2021-01-01&format=text: attempt #1 May 15 11:58:20.432453 ignition[1013]: GET result: OK May 15 11:58:20.432534 ignition[1013]: config has been read from IMDS userdata May 15 11:58:20.434552 unknown[1013]: fetched base config from "system" May 15 11:58:20.432562 ignition[1013]: parsing config with SHA512: f5b3cde9eb38806ade4947433bf06a76e976ec166bcf633ed7f5f3941f3fc840c18464b0d367a5637a4ed6ca4a22aac111a84b960fd0e4c9da4fefcb93a1fe94 May 15 11:58:20.434557 unknown[1013]: fetched base config from "system" May 15 11:58:20.434840 ignition[1013]: fetch: fetch complete May 15 11:58:20.434561 unknown[1013]: fetched user config from "azure" May 15 11:58:20.434845 ignition[1013]: fetch: fetch passed May 15 11:58:20.436712 systemd[1]: Finished ignition-fetch.service - Ignition (fetch). May 15 11:58:20.434900 ignition[1013]: Ignition finished successfully May 15 11:58:20.444802 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... May 15 11:58:20.481212 ignition[1019]: Ignition 2.21.0 May 15 11:58:20.483896 ignition[1019]: Stage: kargs May 15 11:58:20.484066 ignition[1019]: no configs at "/usr/lib/ignition/base.d" May 15 11:58:20.488656 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). May 15 11:58:20.484074 ignition[1019]: no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:20.497777 systemd[1]: Starting ignition-disks.service - Ignition (disks)... May 15 11:58:20.484801 ignition[1019]: kargs: kargs passed May 15 11:58:20.484848 ignition[1019]: Ignition finished successfully May 15 11:58:20.525012 ignition[1025]: Ignition 2.21.0 May 15 11:58:20.525024 ignition[1025]: Stage: disks May 15 11:58:20.528502 systemd[1]: Finished ignition-disks.service - Ignition (disks). May 15 11:58:20.525158 ignition[1025]: no configs at "/usr/lib/ignition/base.d" May 15 11:58:20.534466 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. May 15 11:58:20.525166 ignition[1025]: no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:20.541940 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. May 15 11:58:20.525517 ignition[1025]: disks: disks passed May 15 11:58:20.550094 systemd[1]: Reached target local-fs.target - Local File Systems. May 15 11:58:20.525549 ignition[1025]: Ignition finished successfully May 15 11:58:20.557868 systemd[1]: Reached target sysinit.target - System Initialization. May 15 11:58:20.566624 systemd[1]: Reached target basic.target - Basic System. May 15 11:58:20.575535 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... May 15 11:58:20.597872 systemd-networkd[1004]: eth0: Gained IPv6LL May 15 11:58:20.681574 systemd-fsck[1034]: ROOT: clean, 15/7326000 files, 477845/7359488 blocks May 15 11:58:20.688853 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. May 15 11:58:20.695014 systemd[1]: Mounting sysroot.mount - /sysroot... May 15 11:58:20.725745 systemd-networkd[1004]: enP22304s1: Gained IPv6LL May 15 11:58:20.970610 kernel: EXT4-fs (sda9): mounted filesystem 7753583f-75f7-43aa-89cb-b5e5a7f28ed5 r/w with ordered data mode. Quota mode: none. May 15 11:58:20.970890 systemd[1]: Mounted sysroot.mount - /sysroot. May 15 11:58:20.975071 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. May 15 11:58:20.998500 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... May 15 11:58:21.006089 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... May 15 11:58:21.014154 systemd[1]: Starting flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent... May 15 11:58:21.025052 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). May 15 11:58:21.026330 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. May 15 11:58:21.041429 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. May 15 11:58:21.049780 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... May 15 11:58:21.070679 kernel: BTRFS: device label OEM devid 1 transid 15 /dev/sda6 (8:6) scanned by mount (1048) May 15 11:58:21.080641 kernel: BTRFS info (device sda6): first mount of filesystem 3936141b-01f3-466e-a92a-4f7ff09b25a9 May 15 11:58:21.080680 kernel: BTRFS info (device sda6): using crc32c (crc32c-generic) checksum algorithm May 15 11:58:21.084148 kernel: BTRFS info (device sda6): using free-space-tree May 15 11:58:21.086869 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. May 15 11:58:21.551458 coreos-metadata[1050]: May 15 11:58:21.551 INFO Fetching http://168.63.129.16/?comp=versions: Attempt #1 May 15 11:58:21.559608 coreos-metadata[1050]: May 15 11:58:21.559 INFO Fetch successful May 15 11:58:21.563436 coreos-metadata[1050]: May 15 11:58:21.563 INFO Fetching http://169.254.169.254/metadata/instance/compute/name?api-version=2017-08-01&format=text: Attempt #1 May 15 11:58:21.578859 coreos-metadata[1050]: May 15 11:58:21.578 INFO Fetch successful May 15 11:58:21.596923 coreos-metadata[1050]: May 15 11:58:21.596 INFO wrote hostname ci-4334.0.0-a-072134ebcf to /sysroot/etc/hostname May 15 11:58:21.603848 systemd[1]: Finished flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent. May 15 11:58:22.013642 initrd-setup-root[1080]: cut: /sysroot/etc/passwd: No such file or directory May 15 11:58:22.035277 initrd-setup-root[1087]: cut: /sysroot/etc/group: No such file or directory May 15 11:58:22.040891 initrd-setup-root[1094]: cut: /sysroot/etc/shadow: No such file or directory May 15 11:58:22.048020 initrd-setup-root[1101]: cut: /sysroot/etc/gshadow: No such file or directory May 15 11:58:22.948942 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. May 15 11:58:22.954194 systemd[1]: Starting ignition-mount.service - Ignition (mount)... May 15 11:58:22.975092 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... May 15 11:58:22.984729 systemd[1]: sysroot-oem.mount: Deactivated successfully. May 15 11:58:22.997621 kernel: BTRFS info (device sda6): last unmount of filesystem 3936141b-01f3-466e-a92a-4f7ff09b25a9 May 15 11:58:23.006847 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. May 15 11:58:23.018381 ignition[1172]: INFO : Ignition 2.21.0 May 15 11:58:23.018381 ignition[1172]: INFO : Stage: mount May 15 11:58:23.024713 ignition[1172]: INFO : no configs at "/usr/lib/ignition/base.d" May 15 11:58:23.024713 ignition[1172]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:23.024713 ignition[1172]: INFO : mount: mount passed May 15 11:58:23.024713 ignition[1172]: INFO : Ignition finished successfully May 15 11:58:23.023779 systemd[1]: Finished ignition-mount.service - Ignition (mount). May 15 11:58:23.029467 systemd[1]: Starting ignition-files.service - Ignition (files)... May 15 11:58:23.053715 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... May 15 11:58:23.078619 kernel: BTRFS: device label OEM devid 1 transid 15 /dev/sda6 (8:6) scanned by mount (1180) May 15 11:58:23.090127 kernel: BTRFS info (device sda6): first mount of filesystem 3936141b-01f3-466e-a92a-4f7ff09b25a9 May 15 11:58:23.090137 kernel: BTRFS info (device sda6): using crc32c (crc32c-generic) checksum algorithm May 15 11:58:23.093764 kernel: BTRFS info (device sda6): using free-space-tree May 15 11:58:23.109208 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. May 15 11:58:23.136237 ignition[1197]: INFO : Ignition 2.21.0 May 15 11:58:23.136237 ignition[1197]: INFO : Stage: files May 15 11:58:23.144087 ignition[1197]: INFO : no configs at "/usr/lib/ignition/base.d" May 15 11:58:23.144087 ignition[1197]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:23.144087 ignition[1197]: DEBUG : files: compiled without relabeling support, skipping May 15 11:58:23.157012 ignition[1197]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" May 15 11:58:23.157012 ignition[1197]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" May 15 11:58:23.185031 ignition[1197]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" May 15 11:58:23.190672 ignition[1197]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" May 15 11:58:23.190672 ignition[1197]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" May 15 11:58:23.185397 unknown[1197]: wrote ssh authorized keys file for user: core May 15 11:58:23.214754 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/home/core/install.sh" May 15 11:58:23.221687 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/home/core/install.sh" May 15 11:58:23.232389 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(4): [started] writing file "/sysroot/etc/flatcar/update.conf" May 15 11:58:23.239217 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(4): [finished] writing file "/sysroot/etc/flatcar/update.conf" May 15 11:58:23.239217 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(5): [started] writing link "/sysroot/etc/extensions/kubernetes.raw" -> "/opt/extensions/kubernetes/kubernetes-v1.31.0-arm64.raw" May 15 11:58:23.256334 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(5): [finished] writing link "/sysroot/etc/extensions/kubernetes.raw" -> "/opt/extensions/kubernetes/kubernetes-v1.31.0-arm64.raw" May 15 11:58:23.256334 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(6): [started] writing file "/sysroot/opt/extensions/kubernetes/kubernetes-v1.31.0-arm64.raw" May 15 11:58:23.274535 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(6): GET https://github.com/flatcar/sysext-bakery/releases/download/latest/kubernetes-v1.31.0-arm64.raw: attempt #1 May 15 11:58:23.698250 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(6): GET result: OK May 15 11:58:23.881739 ignition[1197]: INFO : files: createFilesystemsFiles: createFiles: op(6): [finished] writing file "/sysroot/opt/extensions/kubernetes/kubernetes-v1.31.0-arm64.raw" May 15 11:58:23.890851 ignition[1197]: INFO : files: createResultFile: createFiles: op(7): [started] writing file "/sysroot/etc/.ignition-result.json" May 15 11:58:23.890851 ignition[1197]: INFO : files: createResultFile: createFiles: op(7): [finished] writing file "/sysroot/etc/.ignition-result.json" May 15 11:58:23.890851 ignition[1197]: INFO : files: files passed May 15 11:58:23.890851 ignition[1197]: INFO : Ignition finished successfully May 15 11:58:23.891188 systemd[1]: Finished ignition-files.service - Ignition (files). May 15 11:58:23.903207 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... May 15 11:58:23.921026 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... May 15 11:58:23.930318 systemd[1]: ignition-quench.service: Deactivated successfully. May 15 11:58:23.930396 systemd[1]: Finished ignition-quench.service - Ignition (record completion). May 15 11:58:23.957963 initrd-setup-root-after-ignition[1226]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory May 15 11:58:23.957963 initrd-setup-root-after-ignition[1226]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory May 15 11:58:23.972181 initrd-setup-root-after-ignition[1230]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory May 15 11:58:23.972694 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. May 15 11:58:23.985452 systemd[1]: Reached target ignition-complete.target - Ignition Complete. May 15 11:58:23.995816 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... May 15 11:58:24.035052 systemd[1]: initrd-parse-etc.service: Deactivated successfully. May 15 11:58:24.035150 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. May 15 11:58:24.043949 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. May 15 11:58:24.052863 systemd[1]: Reached target initrd.target - Initrd Default Target. May 15 11:58:24.060504 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. May 15 11:58:24.061088 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... May 15 11:58:24.095028 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. May 15 11:58:24.101765 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... May 15 11:58:24.129574 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. May 15 11:58:24.134091 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. May 15 11:58:24.143246 systemd[1]: Stopped target timers.target - Timer Units. May 15 11:58:24.150709 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. May 15 11:58:24.150808 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. May 15 11:58:24.162087 systemd[1]: Stopped target initrd.target - Initrd Default Target. May 15 11:58:24.166435 systemd[1]: Stopped target basic.target - Basic System. May 15 11:58:24.174860 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. May 15 11:58:24.182651 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. May 15 11:58:24.190372 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. May 15 11:58:24.198605 systemd[1]: Stopped target initrd-usr-fs.target - Initrd /usr File System. May 15 11:58:24.207110 systemd[1]: Stopped target remote-fs.target - Remote File Systems. May 15 11:58:24.215243 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. May 15 11:58:24.224662 systemd[1]: Stopped target sysinit.target - System Initialization. May 15 11:58:24.233407 systemd[1]: Stopped target local-fs.target - Local File Systems. May 15 11:58:24.242430 systemd[1]: Stopped target swap.target - Swaps. May 15 11:58:24.249455 systemd[1]: dracut-pre-mount.service: Deactivated successfully. May 15 11:58:24.249558 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. May 15 11:58:24.260819 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. May 15 11:58:24.265346 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). May 15 11:58:24.273707 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. May 15 11:58:24.273767 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. May 15 11:58:24.282622 systemd[1]: dracut-initqueue.service: Deactivated successfully. May 15 11:58:24.282714 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. May 15 11:58:24.295839 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. May 15 11:58:24.295940 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. May 15 11:58:24.305010 systemd[1]: ignition-files.service: Deactivated successfully. May 15 11:58:24.305084 systemd[1]: Stopped ignition-files.service - Ignition (files). May 15 11:58:24.314077 systemd[1]: flatcar-metadata-hostname.service: Deactivated successfully. May 15 11:58:24.314144 systemd[1]: Stopped flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent. May 15 11:58:24.327780 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... May 15 11:58:24.341028 systemd[1]: kmod-static-nodes.service: Deactivated successfully. May 15 11:58:24.379216 ignition[1250]: INFO : Ignition 2.21.0 May 15 11:58:24.379216 ignition[1250]: INFO : Stage: umount May 15 11:58:24.379216 ignition[1250]: INFO : no configs at "/usr/lib/ignition/base.d" May 15 11:58:24.379216 ignition[1250]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/azure" May 15 11:58:24.379216 ignition[1250]: INFO : umount: umount passed May 15 11:58:24.379216 ignition[1250]: INFO : Ignition finished successfully May 15 11:58:24.341160 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. May 15 11:58:24.366091 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... May 15 11:58:24.382672 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. May 15 11:58:24.382810 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. May 15 11:58:24.389400 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. May 15 11:58:24.389483 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. May 15 11:58:24.411641 systemd[1]: sysroot-boot.mount: Deactivated successfully. May 15 11:58:24.412228 systemd[1]: ignition-mount.service: Deactivated successfully. May 15 11:58:24.412323 systemd[1]: Stopped ignition-mount.service - Ignition (mount). May 15 11:58:24.418991 systemd[1]: ignition-disks.service: Deactivated successfully. May 15 11:58:24.419198 systemd[1]: Stopped ignition-disks.service - Ignition (disks). May 15 11:58:24.427966 systemd[1]: ignition-kargs.service: Deactivated successfully. May 15 11:58:24.428022 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). May 15 11:58:24.435284 systemd[1]: ignition-fetch.service: Deactivated successfully. May 15 11:58:24.435330 systemd[1]: Stopped ignition-fetch.service - Ignition (fetch). May 15 11:58:24.443741 systemd[1]: Stopped target network.target - Network. May 15 11:58:24.451290 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. May 15 11:58:24.451367 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). May 15 11:58:24.459972 systemd[1]: Stopped target paths.target - Path Units. May 15 11:58:24.468651 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. May 15 11:58:24.476037 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. May 15 11:58:24.481732 systemd[1]: Stopped target slices.target - Slice Units. May 15 11:58:24.489552 systemd[1]: Stopped target sockets.target - Socket Units. May 15 11:58:24.496810 systemd[1]: iscsid.socket: Deactivated successfully. May 15 11:58:24.496856 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. May 15 11:58:24.504424 systemd[1]: iscsiuio.socket: Deactivated successfully. May 15 11:58:24.504455 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. May 15 11:58:24.512503 systemd[1]: ignition-setup.service: Deactivated successfully. May 15 11:58:24.512558 systemd[1]: Stopped ignition-setup.service - Ignition (setup). May 15 11:58:24.520149 systemd[1]: ignition-setup-pre.service: Deactivated successfully. May 15 11:58:24.520178 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. May 15 11:58:24.527577 systemd[1]: Stopping systemd-networkd.service - Network Configuration... May 15 11:58:24.534741 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... May 15 11:58:24.554053 systemd[1]: systemd-resolved.service: Deactivated successfully. May 15 11:58:24.554152 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. May 15 11:58:24.565631 systemd[1]: run-credentials-systemd\x2dresolved.service.mount: Deactivated successfully. May 15 11:58:24.565832 systemd[1]: systemd-networkd.service: Deactivated successfully. May 15 11:58:24.565925 systemd[1]: Stopped systemd-networkd.service - Network Configuration. May 15 11:58:24.580235 systemd[1]: run-credentials-systemd\x2dnetworkd.service.mount: Deactivated successfully. May 15 11:58:24.580441 systemd[1]: initrd-cleanup.service: Deactivated successfully. May 15 11:58:24.580511 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. May 15 11:58:24.745676 kernel: hv_netvsc 00224876-fffc-0022-4876-fffc00224876 eth0: Data path switched from VF: enP22304s1 May 15 11:58:24.591289 systemd[1]: Stopped target network-pre.target - Preparation for Network. May 15 11:58:24.597234 systemd[1]: systemd-networkd.socket: Deactivated successfully. May 15 11:58:24.597273 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. May 15 11:58:24.611451 systemd[1]: Stopping network-cleanup.service - Network Cleanup... May 15 11:58:24.624626 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. May 15 11:58:24.624690 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. May 15 11:58:24.630537 systemd[1]: systemd-sysctl.service: Deactivated successfully. May 15 11:58:24.630583 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. May 15 11:58:24.641387 systemd[1]: systemd-modules-load.service: Deactivated successfully. May 15 11:58:24.641425 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. May 15 11:58:24.646024 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. May 15 11:58:24.646063 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. May 15 11:58:24.658494 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... May 15 11:58:24.666392 systemd[1]: run-credentials-systemd\x2dsysctl.service.mount: Deactivated successfully. May 15 11:58:24.666443 systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup.service.mount: Deactivated successfully. May 15 11:58:24.666721 systemd[1]: sysroot-boot.service: Deactivated successfully. May 15 11:58:24.666798 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. May 15 11:58:24.674442 systemd[1]: initrd-setup-root.service: Deactivated successfully. May 15 11:58:24.674530 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. May 15 11:58:24.699678 systemd[1]: systemd-udevd.service: Deactivated successfully. May 15 11:58:24.699809 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. May 15 11:58:24.711047 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. May 15 11:58:24.711079 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. May 15 11:58:24.715152 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. May 15 11:58:24.715174 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. May 15 11:58:24.724110 systemd[1]: dracut-pre-udev.service: Deactivated successfully. May 15 11:58:24.724146 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. May 15 11:58:24.736869 systemd[1]: dracut-cmdline.service: Deactivated successfully. May 15 11:58:24.736956 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. May 15 11:58:24.754912 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. May 15 11:58:24.754987 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. May 15 11:58:24.769779 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... May 15 11:58:24.949408 systemd-journald[225]: Received SIGTERM from PID 1 (systemd). May 15 11:58:24.783774 systemd[1]: systemd-network-generator.service: Deactivated successfully. May 15 11:58:24.783863 systemd[1]: Stopped systemd-network-generator.service - Generate network units from Kernel command line. May 15 11:58:24.795153 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. May 15 11:58:24.795202 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. May 15 11:58:24.813173 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. May 15 11:58:24.813246 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:24.823778 systemd[1]: run-credentials-systemd\x2dnetwork\x2dgenerator.service.mount: Deactivated successfully. May 15 11:58:24.823838 systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup\x2ddev.service.mount: Deactivated successfully. May 15 11:58:24.823864 systemd[1]: run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Deactivated successfully. May 15 11:58:24.824162 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. May 15 11:58:24.824325 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. May 15 11:58:24.836473 systemd[1]: network-cleanup.service: Deactivated successfully. May 15 11:58:24.836638 systemd[1]: Stopped network-cleanup.service - Network Cleanup. May 15 11:58:24.845548 systemd[1]: Reached target initrd-switch-root.target - Switch Root. May 15 11:58:24.857230 systemd[1]: Starting initrd-switch-root.service - Switch Root... May 15 11:58:24.885129 systemd[1]: Switching root. May 15 11:58:25.022053 systemd-journald[225]: Journal stopped May 15 11:58:29.251076 kernel: SELinux: policy capability network_peer_controls=1 May 15 11:58:29.251093 kernel: SELinux: policy capability open_perms=1 May 15 11:58:29.251102 kernel: SELinux: policy capability extended_socket_class=1 May 15 11:58:29.251107 kernel: SELinux: policy capability always_check_network=0 May 15 11:58:29.251114 kernel: SELinux: policy capability cgroup_seclabel=1 May 15 11:58:29.251119 kernel: SELinux: policy capability nnp_nosuid_transition=1 May 15 11:58:29.251125 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 May 15 11:58:29.251130 kernel: SELinux: policy capability ioctl_skip_cloexec=0 May 15 11:58:29.251135 kernel: SELinux: policy capability userspace_initial_context=0 May 15 11:58:29.251141 kernel: audit: type=1403 audit(1747310305.861:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 May 15 11:58:29.251148 systemd[1]: Successfully loaded SELinux policy in 114.682ms. May 15 11:58:29.251155 systemd[1]: Relabeled /dev/, /dev/shm/, /run/ in 8.093ms. May 15 11:58:29.251161 systemd[1]: systemd 256.8 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP -GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) May 15 11:58:29.251167 systemd[1]: Detected virtualization microsoft. May 15 11:58:29.251174 systemd[1]: Detected architecture arm64. May 15 11:58:29.251180 systemd[1]: Detected first boot. May 15 11:58:29.251187 systemd[1]: Hostname set to . May 15 11:58:29.251192 systemd[1]: Initializing machine ID from random generator. May 15 11:58:29.251198 zram_generator::config[1292]: No configuration found. May 15 11:58:29.251204 kernel: NET: Registered PF_VSOCK protocol family May 15 11:58:29.251209 systemd[1]: Populated /etc with preset unit settings. May 15 11:58:29.251216 systemd[1]: run-credentials-systemd\x2djournald.service.mount: Deactivated successfully. May 15 11:58:29.251223 systemd[1]: initrd-switch-root.service: Deactivated successfully. May 15 11:58:29.251228 systemd[1]: Stopped initrd-switch-root.service - Switch Root. May 15 11:58:29.251234 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. May 15 11:58:29.251241 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. May 15 11:58:29.251247 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. May 15 11:58:29.251253 systemd[1]: Created slice system-getty.slice - Slice /system/getty. May 15 11:58:29.251259 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. May 15 11:58:29.251265 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. May 15 11:58:29.251271 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. May 15 11:58:29.251277 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. May 15 11:58:29.251283 systemd[1]: Created slice user.slice - User and Session Slice. May 15 11:58:29.251289 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. May 15 11:58:29.251295 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. May 15 11:58:29.251301 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. May 15 11:58:29.251307 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. May 15 11:58:29.251313 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. May 15 11:58:29.251319 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... May 15 11:58:29.251325 systemd[1]: Expecting device dev-ttyAMA0.device - /dev/ttyAMA0... May 15 11:58:29.251333 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). May 15 11:58:29.251339 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. May 15 11:58:29.251345 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. May 15 11:58:29.251350 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. May 15 11:58:29.251357 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. May 15 11:58:29.251364 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. May 15 11:58:29.251370 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. May 15 11:58:29.251376 systemd[1]: Reached target remote-fs.target - Remote File Systems. May 15 11:58:29.251382 systemd[1]: Reached target slices.target - Slice Units. May 15 11:58:29.251388 systemd[1]: Reached target swap.target - Swaps. May 15 11:58:29.251394 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. May 15 11:58:29.251400 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. May 15 11:58:29.251407 systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. May 15 11:58:29.251414 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. May 15 11:58:29.251420 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. May 15 11:58:29.251426 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. May 15 11:58:29.251432 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. May 15 11:58:29.251438 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... May 15 11:58:29.251445 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... May 15 11:58:29.251451 systemd[1]: Mounting media.mount - External Media Directory... May 15 11:58:29.251457 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... May 15 11:58:29.251463 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... May 15 11:58:29.251469 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... May 15 11:58:29.251475 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). May 15 11:58:29.251482 systemd[1]: Reached target machines.target - Containers. May 15 11:58:29.251488 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... May 15 11:58:29.251494 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. May 15 11:58:29.251501 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... May 15 11:58:29.251508 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... May 15 11:58:29.251514 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... May 15 11:58:29.251520 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... May 15 11:58:29.251526 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... May 15 11:58:29.251532 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... May 15 11:58:29.251538 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... May 15 11:58:29.251544 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). May 15 11:58:29.251551 systemd[1]: systemd-fsck-root.service: Deactivated successfully. May 15 11:58:29.251557 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. May 15 11:58:29.251563 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. May 15 11:58:29.251569 systemd[1]: Stopped systemd-fsck-usr.service. May 15 11:58:29.251575 kernel: fuse: init (API version 7.41) May 15 11:58:29.251581 systemd[1]: systemd-hibernate-clear.service - Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67). May 15 11:58:29.251587 systemd[1]: Starting systemd-journald.service - Journal Service... May 15 11:58:29.251603 kernel: loop: module loaded May 15 11:58:29.251610 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... May 15 11:58:29.251616 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... May 15 11:58:29.251622 kernel: ACPI: bus type drm_connector registered May 15 11:58:29.251628 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... May 15 11:58:29.251645 systemd-journald[1394]: Collecting audit messages is disabled. May 15 11:58:29.251661 systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... May 15 11:58:29.251668 systemd-journald[1394]: Journal started May 15 11:58:29.251683 systemd-journald[1394]: Runtime Journal (/run/log/journal/228af0426b264f1eb4da949ed030322b) is 8M, max 78.5M, 70.5M free. May 15 11:58:28.500230 systemd[1]: Queued start job for default target multi-user.target. May 15 11:58:28.506042 systemd[1]: Unnecessary job was removed for dev-sda6.device - /dev/sda6. May 15 11:58:28.506439 systemd[1]: systemd-journald.service: Deactivated successfully. May 15 11:58:28.507770 systemd[1]: systemd-journald.service: Consumed 2.280s CPU time. May 15 11:58:29.280891 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... May 15 11:58:29.288103 systemd[1]: verity-setup.service: Deactivated successfully. May 15 11:58:29.288155 systemd[1]: Stopped verity-setup.service. May 15 11:58:29.302413 systemd[1]: Started systemd-journald.service - Journal Service. May 15 11:58:29.302932 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. May 15 11:58:29.307067 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. May 15 11:58:29.311838 systemd[1]: Mounted media.mount - External Media Directory. May 15 11:58:29.315919 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. May 15 11:58:29.321188 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. May 15 11:58:29.326174 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. May 15 11:58:29.330908 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. May 15 11:58:29.336318 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. May 15 11:58:29.342361 systemd[1]: modprobe@configfs.service: Deactivated successfully. May 15 11:58:29.342497 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. May 15 11:58:29.347660 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. May 15 11:58:29.347778 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. May 15 11:58:29.353513 systemd[1]: modprobe@drm.service: Deactivated successfully. May 15 11:58:29.353634 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. May 15 11:58:29.358176 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. May 15 11:58:29.358293 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. May 15 11:58:29.363565 systemd[1]: modprobe@fuse.service: Deactivated successfully. May 15 11:58:29.363710 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. May 15 11:58:29.368984 systemd[1]: modprobe@loop.service: Deactivated successfully. May 15 11:58:29.369116 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. May 15 11:58:29.373948 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. May 15 11:58:29.379118 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. May 15 11:58:29.385607 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. May 15 11:58:29.392545 systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. May 15 11:58:29.399062 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. May 15 11:58:29.414065 systemd[1]: Reached target network-pre.target - Preparation for Network. May 15 11:58:29.419894 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... May 15 11:58:29.427223 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... May 15 11:58:29.432311 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). May 15 11:58:29.432338 systemd[1]: Reached target local-fs.target - Local File Systems. May 15 11:58:29.437853 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. May 15 11:58:29.443959 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... May 15 11:58:29.448296 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. May 15 11:58:29.463857 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... May 15 11:58:29.475410 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... May 15 11:58:29.479945 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). May 15 11:58:29.482708 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... May 15 11:58:29.486851 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. May 15 11:58:29.487583 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... May 15 11:58:29.493971 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... May 15 11:58:29.500746 systemd[1]: Starting systemd-sysusers.service - Create System Users... May 15 11:58:29.503049 systemd-journald[1394]: Time spent on flushing to /var/log/journal/228af0426b264f1eb4da949ed030322b is 8.165ms for 916 entries. May 15 11:58:29.503049 systemd-journald[1394]: System Journal (/var/log/journal/228af0426b264f1eb4da949ed030322b) is 8M, max 2.6G, 2.6G free. May 15 11:58:29.608764 systemd-journald[1394]: Received client request to flush runtime journal. May 15 11:58:29.608812 kernel: loop0: detected capacity change from 0 to 138376 May 15 11:58:29.511098 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. May 15 11:58:29.515636 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. May 15 11:58:29.565118 systemd[1]: Finished systemd-sysusers.service - Create System Users. May 15 11:58:29.574735 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... May 15 11:58:29.584731 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. May 15 11:58:29.593430 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. May 15 11:58:29.599707 systemd[1]: Starting systemd-machine-id-commit.service - Save Transient machine-id to Disk... May 15 11:58:29.609558 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. May 15 11:58:29.614309 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. May 15 11:58:29.646702 systemd-tmpfiles[1439]: ACLs are not supported, ignoring. May 15 11:58:29.646715 systemd-tmpfiles[1439]: ACLs are not supported, ignoring. May 15 11:58:29.651470 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. May 15 11:58:29.661460 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. May 15 11:58:29.661985 systemd[1]: Finished systemd-machine-id-commit.service - Save Transient machine-id to Disk. May 15 11:58:29.996624 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher May 15 11:58:30.046713 kernel: loop1: detected capacity change from 0 to 107312 May 15 11:58:30.353621 kernel: loop2: detected capacity change from 0 to 189592 May 15 11:58:30.383623 kernel: loop3: detected capacity change from 0 to 28640 May 15 11:58:30.472231 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. May 15 11:58:30.478318 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... May 15 11:58:30.508277 systemd-udevd[1454]: Using default interface naming scheme 'v255'. May 15 11:58:30.739629 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. May 15 11:58:30.754647 systemd[1]: Starting systemd-networkd.service - Network Configuration... May 15 11:58:30.799556 systemd[1]: Condition check resulted in dev-ttyAMA0.device - /dev/ttyAMA0 being skipped. May 15 11:58:30.808829 systemd[1]: Starting systemd-userdbd.service - User Database Manager... May 15 11:58:30.850618 kernel: loop4: detected capacity change from 0 to 138376 May 15 11:58:30.875626 kernel: loop5: detected capacity change from 0 to 107312 May 15 11:58:30.881620 kernel: mousedev: PS/2 mouse device common for all mice May 15 11:58:30.887610 kernel: loop6: detected capacity change from 0 to 189592 May 15 11:58:30.897665 kernel: hv_storvsc f8b3781a-1e82-4818-a1c3-63d806ec15bb: tag#285 cmd 0x85 status: scsi 0x2 srb 0x6 hv 0xc0000001 May 15 11:58:30.907736 kernel: loop7: detected capacity change from 0 to 28640 May 15 11:58:30.909765 systemd[1]: Started systemd-userdbd.service - User Database Manager. May 15 11:58:30.914462 (sd-merge)[1492]: Using extensions 'containerd-flatcar', 'docker-flatcar', 'kubernetes', 'oem-azure'. May 15 11:58:30.914815 (sd-merge)[1492]: Merged extensions into '/usr'. May 15 11:58:30.921706 systemd[1]: Reload requested from client PID 1432 ('systemd-sysext') (unit systemd-sysext.service)... May 15 11:58:30.921718 systemd[1]: Reloading... May 15 11:58:31.005856 kernel: hv_vmbus: registering driver hv_balloon May 15 11:58:31.005944 kernel: hv_balloon: Using Dynamic Memory protocol version 2.0 May 15 11:58:31.015502 kernel: hv_vmbus: registering driver hyperv_fb May 15 11:58:31.015565 zram_generator::config[1553]: No configuration found. May 15 11:58:31.015591 kernel: hv_balloon: Memory hot add disabled on ARM64 May 15 11:58:31.048627 kernel: hyperv_fb: Synthvid Version major 3, minor 5 May 15 11:58:31.048699 kernel: hyperv_fb: Screen resolution: 1024x768, Color depth: 32, Frame buffer size: 8388608 May 15 11:58:31.059638 kernel: Console: switching to colour dummy device 80x25 May 15 11:58:31.068778 kernel: Console: switching to colour frame buffer device 128x48 May 15 11:58:31.135963 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. May 15 11:58:31.159431 systemd-networkd[1482]: lo: Link UP May 15 11:58:31.159440 systemd-networkd[1482]: lo: Gained carrier May 15 11:58:31.162233 systemd-networkd[1482]: Enumeration completed May 15 11:58:31.162861 systemd-networkd[1482]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. May 15 11:58:31.162864 systemd-networkd[1482]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. May 15 11:58:31.213621 kernel: mlx5_core 5720:00:02.0 enP22304s1: Link up May 15 11:58:31.235692 kernel: hv_netvsc 00224876-fffc-0022-4876-fffc00224876 eth0: Data path switched to VF: enP22304s1 May 15 11:58:31.235929 systemd-networkd[1482]: enP22304s1: Link UP May 15 11:58:31.235988 systemd-networkd[1482]: eth0: Link UP May 15 11:58:31.235990 systemd-networkd[1482]: eth0: Gained carrier May 15 11:58:31.236006 systemd-networkd[1482]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. May 15 11:58:31.240794 systemd-networkd[1482]: enP22304s1: Gained carrier May 15 11:58:31.246628 systemd-networkd[1482]: eth0: DHCPv4 address 10.200.20.25/24, gateway 10.200.20.1 acquired from 168.63.129.16 May 15 11:58:31.270617 kernel: MACsec IEEE 802.1AE May 15 11:58:31.287017 systemd[1]: Reloading finished in 365 ms. May 15 11:58:31.307719 systemd[1]: Started systemd-networkd.service - Network Configuration. May 15 11:58:31.313588 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. May 15 11:58:31.342606 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - Virtual_Disk OEM. May 15 11:58:31.357743 systemd[1]: Starting ensure-sysext.service... May 15 11:58:31.361518 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... May 15 11:58:31.369606 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... May 15 11:58:31.375280 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... May 15 11:58:31.380834 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... May 15 11:58:31.388647 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... May 15 11:58:31.404112 systemd-tmpfiles[1672]: /usr/lib/tmpfiles.d/nfs-utils.conf:6: Duplicate line for path "/var/lib/nfs/sm", ignoring. May 15 11:58:31.405095 systemd-tmpfiles[1672]: /usr/lib/tmpfiles.d/nfs-utils.conf:7: Duplicate line for path "/var/lib/nfs/sm.bak", ignoring. May 15 11:58:31.405387 systemd-tmpfiles[1672]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. May 15 11:58:31.405647 systemd-tmpfiles[1672]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. May 15 11:58:31.406181 systemd-tmpfiles[1672]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. May 15 11:58:31.406409 systemd[1]: Reload requested from client PID 1668 ('systemctl') (unit ensure-sysext.service)... May 15 11:58:31.406419 systemd[1]: Reloading... May 15 11:58:31.407237 systemd-tmpfiles[1672]: ACLs are not supported, ignoring. May 15 11:58:31.407361 systemd-tmpfiles[1672]: ACLs are not supported, ignoring. May 15 11:58:31.424363 systemd-tmpfiles[1672]: Detected autofs mount point /boot during canonicalization of boot. May 15 11:58:31.424371 systemd-tmpfiles[1672]: Skipping /boot May 15 11:58:31.438035 systemd-tmpfiles[1672]: Detected autofs mount point /boot during canonicalization of boot. May 15 11:58:31.438050 systemd-tmpfiles[1672]: Skipping /boot May 15 11:58:31.469623 zram_generator::config[1704]: No configuration found. May 15 11:58:31.542272 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. May 15 11:58:31.617105 systemd[1]: Reloading finished in 210 ms. May 15 11:58:31.635059 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. May 15 11:58:31.652381 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. May 15 11:58:31.657847 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. May 15 11:58:31.671801 systemd[1]: Starting audit-rules.service - Load Audit Rules... May 15 11:58:31.706032 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... May 15 11:58:31.719694 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... May 15 11:58:31.727802 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... May 15 11:58:31.732986 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... May 15 11:58:31.739593 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. May 15 11:58:31.740394 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... May 15 11:58:31.748047 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... May 15 11:58:31.757938 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... May 15 11:58:31.761897 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. May 15 11:58:31.761990 systemd[1]: systemd-hibernate-clear.service - Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67). May 15 11:58:31.765168 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. May 15 11:58:31.765308 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. May 15 11:58:31.772313 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. May 15 11:58:31.772454 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. May 15 11:58:31.777345 systemd[1]: modprobe@loop.service: Deactivated successfully. May 15 11:58:31.777466 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. May 15 11:58:31.787397 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. May 15 11:58:31.788810 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... May 15 11:58:31.798525 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... May 15 11:58:31.809077 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... May 15 11:58:31.814880 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. May 15 11:58:31.814980 systemd[1]: systemd-hibernate-clear.service - Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67). May 15 11:58:31.816350 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. May 15 11:58:31.826926 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. May 15 11:58:31.832538 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. May 15 11:58:31.832694 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. May 15 11:58:31.837688 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. May 15 11:58:31.838776 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. May 15 11:58:31.844371 systemd[1]: modprobe@loop.service: Deactivated successfully. May 15 11:58:31.844735 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. May 15 11:58:31.856261 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. May 15 11:58:31.858717 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... May 15 11:58:31.864902 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... May 15 11:58:31.874332 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... May 15 11:58:31.880206 systemd-resolved[1772]: Positive Trust Anchors: May 15 11:58:31.881642 systemd-resolved[1772]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d May 15 11:58:31.881669 systemd-resolved[1772]: 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 May 15 11:58:31.881791 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... May 15 11:58:31.887586 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. May 15 11:58:31.887763 systemd[1]: systemd-hibernate-clear.service - Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67). May 15 11:58:31.887867 systemd[1]: Reached target time-set.target - System Time Set. May 15 11:58:31.889863 systemd-resolved[1772]: Using system hostname 'ci-4334.0.0-a-072134ebcf'. May 15 11:58:31.900089 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. May 15 11:58:31.905426 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. May 15 11:58:31.905579 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. May 15 11:58:31.910517 systemd[1]: modprobe@drm.service: Deactivated successfully. May 15 11:58:31.910833 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. May 15 11:58:31.915676 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. May 15 11:58:31.915806 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. May 15 11:58:31.920972 systemd[1]: Started systemd-resolved.service - Network Name Resolution. May 15 11:58:31.925582 systemd[1]: modprobe@loop.service: Deactivated successfully. May 15 11:58:31.925750 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. May 15 11:58:31.935814 systemd[1]: Finished ensure-sysext.service. May 15 11:58:31.939217 augenrules[1817]: No rules May 15 11:58:31.940452 systemd[1]: audit-rules.service: Deactivated successfully. May 15 11:58:31.940658 systemd[1]: Finished audit-rules.service - Load Audit Rules. May 15 11:58:31.946128 systemd[1]: Reached target network.target - Network. May 15 11:58:31.950322 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. May 15 11:58:31.955628 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). May 15 11:58:31.955684 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. May 15 11:58:32.157173 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. May 15 11:58:32.162480 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). May 15 11:58:32.564782 systemd-networkd[1482]: enP22304s1: Gained IPv6LL May 15 11:58:32.756713 systemd-networkd[1482]: eth0: Gained IPv6LL May 15 11:58:32.758179 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. May 15 11:58:32.764259 systemd[1]: Reached target network-online.target - Network is Online. May 15 11:58:35.861895 ldconfig[1427]: /sbin/ldconfig: /usr/lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. May 15 11:58:35.878507 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. May 15 11:58:35.885268 systemd[1]: Starting systemd-update-done.service - Update is Completed... May 15 11:58:35.901767 systemd[1]: Finished systemd-update-done.service - Update is Completed. May 15 11:58:35.906451 systemd[1]: Reached target sysinit.target - System Initialization. May 15 11:58:35.910836 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. May 15 11:58:35.916213 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. May 15 11:58:35.921388 systemd[1]: Started logrotate.timer - Daily rotation of log files. May 15 11:58:35.925672 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. May 15 11:58:35.930942 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. May 15 11:58:35.936036 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). May 15 11:58:35.936060 systemd[1]: Reached target paths.target - Path Units. May 15 11:58:35.939722 systemd[1]: Reached target timers.target - Timer Units. May 15 11:58:35.944234 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. May 15 11:58:35.950060 systemd[1]: Starting docker.socket - Docker Socket for the API... May 15 11:58:35.956034 systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). May 15 11:58:35.961924 systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). May 15 11:58:35.967287 systemd[1]: Reached target ssh-access.target - SSH Access Available. May 15 11:58:35.973399 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. May 15 11:58:35.978469 systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. May 15 11:58:35.983869 systemd[1]: Listening on docker.socket - Docker Socket for the API. May 15 11:58:35.988570 systemd[1]: Reached target sockets.target - Socket Units. May 15 11:58:35.993355 systemd[1]: Reached target basic.target - Basic System. May 15 11:58:35.997643 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. May 15 11:58:35.997662 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. May 15 11:58:35.999539 systemd[1]: Starting chronyd.service - NTP client/server... May 15 11:58:36.013694 systemd[1]: Starting containerd.service - containerd container runtime... May 15 11:58:36.019702 systemd[1]: Starting coreos-metadata.service - Flatcar Metadata Agent... May 15 11:58:36.028188 systemd[1]: Starting dbus.service - D-Bus System Message Bus... May 15 11:58:36.035440 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... May 15 11:58:36.043820 (chronyd)[1832]: chronyd.service: Referenced but unset environment variable evaluates to an empty string: OPTIONS May 15 11:58:36.048608 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... May 15 11:58:36.054734 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... May 15 11:58:36.055442 jq[1840]: false May 15 11:58:36.060071 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). May 15 11:58:36.062709 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... May 15 11:58:36.068432 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... May 15 11:58:36.073578 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... May 15 11:58:36.079741 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... May 15 11:58:36.085341 chronyd[1849]: chronyd version 4.6.1 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER -SIGND +ASYNCDNS +NTS +SECHASH +IPV6 -DEBUG) May 15 11:58:36.086657 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... May 15 11:58:36.087474 chronyd[1849]: Timezone right/UTC failed leap second check, ignoring May 15 11:58:36.090305 chronyd[1849]: Loaded seccomp filter (level 2) May 15 11:58:36.097717 systemd[1]: Starting systemd-logind.service - User Login Management... May 15 11:58:36.104544 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). May 15 11:58:36.104957 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. May 15 11:58:36.105394 systemd[1]: Starting update-engine.service - Update Engine... May 15 11:58:36.120710 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... May 15 11:58:36.127579 systemd[1]: Started chronyd.service - NTP client/server. May 15 11:58:36.132547 jq[1858]: true May 15 11:58:36.135682 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. May 15 11:58:36.140565 extend-filesystems[1841]: Found loop4 May 15 11:58:36.140565 extend-filesystems[1841]: Found loop5 May 15 11:58:36.140565 extend-filesystems[1841]: Found loop6 May 15 11:58:36.140565 extend-filesystems[1841]: Found loop7 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda May 15 11:58:36.140565 extend-filesystems[1841]: Found sda1 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda2 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda3 May 15 11:58:36.140565 extend-filesystems[1841]: Found usr May 15 11:58:36.140565 extend-filesystems[1841]: Found sda4 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda6 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda7 May 15 11:58:36.140565 extend-filesystems[1841]: Found sda9 May 15 11:58:36.140565 extend-filesystems[1841]: Checking size of /dev/sda9 May 15 11:58:36.385810 update_engine[1856]: I20250515 11:58:36.179214 1856 main.cc:92] Flatcar Update Engine starting May 15 11:58:36.143665 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. May 15 11:58:36.386119 extend-filesystems[1841]: Old size kept for /dev/sda9 May 15 11:58:36.386119 extend-filesystems[1841]: Found sr0 May 15 11:58:36.143831 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. May 15 11:58:36.148391 systemd[1]: motdgen.service: Deactivated successfully. May 15 11:58:36.150131 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. May 15 11:58:36.159566 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. May 15 11:58:36.471207 jq[1874]: true May 15 11:58:36.160323 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. May 15 11:58:36.181050 systemd[1]: extend-filesystems.service: Deactivated successfully. May 15 11:58:36.181218 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. May 15 11:58:36.216919 (ntainerd)[1875]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR May 15 11:58:36.271154 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. May 15 11:58:36.284236 systemd-logind[1852]: New seat seat0. May 15 11:58:36.284910 systemd-logind[1852]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) May 15 11:58:36.473864 bash[1922]: Updated "/home/core/.ssh/authorized_keys" May 15 11:58:36.373158 systemd[1]: Started systemd-logind.service - User Login Management. May 15 11:58:36.473657 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. May 15 11:58:36.482287 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. May 15 11:58:36.493020 sshd_keygen[1857]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 May 15 11:58:36.518623 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. May 15 11:58:36.526750 systemd[1]: Starting issuegen.service - Generate /run/issue... May 15 11:58:36.537181 systemd[1]: Starting waagent.service - Microsoft Azure Linux Agent... May 15 11:58:36.550925 dbus-daemon[1835]: [system] SELinux support is enabled May 15 11:58:36.551695 systemd[1]: Started dbus.service - D-Bus System Message Bus. May 15 11:58:36.558304 update_engine[1856]: I20250515 11:58:36.558257 1856 update_check_scheduler.cc:74] Next update check in 8m11s May 15 11:58:36.562279 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). May 15 11:58:36.562302 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. May 15 11:58:36.571314 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). May 15 11:58:36.571333 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. May 15 11:58:36.587401 dbus-daemon[1835]: [system] Successfully activated service 'org.freedesktop.systemd1' May 15 11:58:36.590099 systemd[1]: issuegen.service: Deactivated successfully. May 15 11:58:36.590280 systemd[1]: Finished issuegen.service - Generate /run/issue. May 15 11:58:36.599755 systemd[1]: Started update-engine.service - Update Engine. May 15 11:58:36.608880 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... May 15 11:58:36.622290 systemd[1]: Started locksmithd.service - Cluster reboot manager. May 15 11:58:36.633122 coreos-metadata[1834]: May 15 11:58:36.632 INFO Fetching http://168.63.129.16/?comp=versions: Attempt #1 May 15 11:58:36.638384 systemd[1]: Started waagent.service - Microsoft Azure Linux Agent. May 15 11:58:36.646959 coreos-metadata[1834]: May 15 11:58:36.646 INFO Fetch successful May 15 11:58:36.646959 coreos-metadata[1834]: May 15 11:58:36.646 INFO Fetching http://168.63.129.16/machine/?comp=goalstate: Attempt #1 May 15 11:58:36.651755 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. May 15 11:58:36.657308 coreos-metadata[1834]: May 15 11:58:36.657 INFO Fetch successful May 15 11:58:36.658439 coreos-metadata[1834]: May 15 11:58:36.658 INFO Fetching http://168.63.129.16/machine/53e64781-2489-48ae-a524-217921423bd5/881fa590%2D4787%2D4e0f%2Db042%2D5a6953f4d44f.%5Fci%2D4334.0.0%2Da%2D072134ebcf?comp=config&type=sharedConfig&incarnation=1: Attempt #1 May 15 11:58:36.660521 coreos-metadata[1834]: May 15 11:58:36.660 INFO Fetch successful May 15 11:58:36.661244 coreos-metadata[1834]: May 15 11:58:36.661 INFO Fetching http://169.254.169.254/metadata/instance/compute/vmSize?api-version=2017-08-01&format=text: Attempt #1 May 15 11:58:36.667919 systemd[1]: Started getty@tty1.service - Getty on tty1. May 15 11:58:36.673800 coreos-metadata[1834]: May 15 11:58:36.673 INFO Fetch successful May 15 11:58:36.676845 systemd[1]: Started serial-getty@ttyAMA0.service - Serial Getty on ttyAMA0. May 15 11:58:36.687140 systemd[1]: Reached target getty.target - Login Prompts. May 15 11:58:36.717297 systemd[1]: Finished coreos-metadata.service - Flatcar Metadata Agent. May 15 11:58:36.723323 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. May 15 11:58:36.769825 locksmithd[1994]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" May 15 11:58:36.867983 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent. May 15 11:58:36.878892 (kubelet)[2016]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_EXTRA_ARGS, KUBELET_KUBEADM_ARGS May 15 11:58:36.996478 containerd[1875]: time="2025-05-15T11:58:36Z" level=warning msg="Ignoring unknown key in TOML" column=1 error="strict mode: fields in the document are missing in the target struct" file=/usr/share/containerd/config.toml key=subreaper row=8 May 15 11:58:36.998611 containerd[1875]: time="2025-05-15T11:58:36.998531936Z" level=info msg="starting containerd" revision=06b99ca80cdbfbc6cc8bd567021738c9af2b36ce version=v2.0.4 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005389984Z" level=warning msg="Configuration migrated from version 2, use `containerd config migrate` to avoid migration" t="6.936µs" May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005415888Z" level=info msg="loading plugin" id=io.containerd.image-verifier.v1.bindir type=io.containerd.image-verifier.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005429352Z" level=info msg="loading plugin" id=io.containerd.internal.v1.opt type=io.containerd.internal.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005551920Z" level=info msg="loading plugin" id=io.containerd.warning.v1.deprecations type=io.containerd.warning.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005562728Z" level=info msg="loading plugin" id=io.containerd.content.v1.content type=io.containerd.content.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005577776Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005630704Z" level=info msg="skip loading plugin" error="no scratch file generator: skip plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 May 15 11:58:37.005649 containerd[1875]: time="2025-05-15T11:58:37.005638488Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.btrfs type=io.containerd.snapshotter.v1 May 15 11:58:37.005810 containerd[1875]: time="2025-05-15T11:58:37.005800088Z" level=info msg="skip loading plugin" 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" id=io.containerd.snapshotter.v1.btrfs type=io.containerd.snapshotter.v1 May 15 11:58:37.005826 containerd[1875]: time="2025-05-15T11:58:37.005810656Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 May 15 11:58:37.005826 containerd[1875]: time="2025-05-15T11:58:37.005818792Z" level=info msg="skip loading plugin" error="devmapper not configured: skip plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 May 15 11:58:37.005826 containerd[1875]: time="2025-05-15T11:58:37.005823912Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.native type=io.containerd.snapshotter.v1 May 15 11:58:37.006074 containerd[1875]: time="2025-05-15T11:58:37.005880792Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.overlayfs type=io.containerd.snapshotter.v1 May 15 11:58:37.006074 containerd[1875]: time="2025-05-15T11:58:37.006018688Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.zfs type=io.containerd.snapshotter.v1 May 15 11:58:37.006074 containerd[1875]: time="2025-05-15T11:58:37.006036664Z" level=info msg="skip loading plugin" error="lstat /var/lib/containerd/io.containerd.snapshotter.v1.zfs: no such file or directory: skip plugin" id=io.containerd.snapshotter.v1.zfs type=io.containerd.snapshotter.v1 May 15 11:58:37.006074 containerd[1875]: time="2025-05-15T11:58:37.006043600Z" level=info msg="loading plugin" id=io.containerd.event.v1.exchange type=io.containerd.event.v1 May 15 11:58:37.006074 containerd[1875]: time="2025-05-15T11:58:37.006070208Z" level=info msg="loading plugin" id=io.containerd.monitor.task.v1.cgroups type=io.containerd.monitor.task.v1 May 15 11:58:37.006240 containerd[1875]: time="2025-05-15T11:58:37.006203872Z" level=info msg="loading plugin" id=io.containerd.metadata.v1.bolt type=io.containerd.metadata.v1 May 15 11:58:37.006271 containerd[1875]: time="2025-05-15T11:58:37.006257856Z" level=info msg="metadata content store policy set" policy=shared May 15 11:58:37.023378 containerd[1875]: time="2025-05-15T11:58:37.023322296Z" level=info msg="loading plugin" id=io.containerd.gc.v1.scheduler type=io.containerd.gc.v1 May 15 11:58:37.023378 containerd[1875]: time="2025-05-15T11:58:37.023367112Z" level=info msg="loading plugin" id=io.containerd.differ.v1.walking type=io.containerd.differ.v1 May 15 11:58:37.023378 containerd[1875]: time="2025-05-15T11:58:37.023378680Z" level=info msg="loading plugin" id=io.containerd.lease.v1.manager type=io.containerd.lease.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023395272Z" level=info msg="loading plugin" id=io.containerd.service.v1.containers-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023403392Z" level=info msg="loading plugin" id=io.containerd.service.v1.content-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023409928Z" level=info msg="loading plugin" id=io.containerd.service.v1.diff-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023417336Z" level=info msg="loading plugin" id=io.containerd.service.v1.images-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023424648Z" level=info msg="loading plugin" id=io.containerd.service.v1.introspection-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023432416Z" level=info msg="loading plugin" id=io.containerd.service.v1.namespaces-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023438376Z" level=info msg="loading plugin" id=io.containerd.service.v1.snapshots-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023443888Z" level=info msg="loading plugin" id=io.containerd.shim.v1.manager type=io.containerd.shim.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023451688Z" level=info msg="loading plugin" id=io.containerd.runtime.v2.task type=io.containerd.runtime.v2 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023565048Z" level=info msg="loading plugin" id=io.containerd.service.v1.tasks-service type=io.containerd.service.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023605568Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.containers type=io.containerd.grpc.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023616800Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.content type=io.containerd.grpc.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023624096Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.diff type=io.containerd.grpc.v1 May 15 11:58:37.023818 containerd[1875]: time="2025-05-15T11:58:37.023631416Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.events type=io.containerd.grpc.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023638800Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.images type=io.containerd.grpc.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023646312Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.introspection type=io.containerd.grpc.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023652872Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.leases type=io.containerd.grpc.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023660632Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.namespaces type=io.containerd.grpc.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023673872Z" level=info msg="loading plugin" id=io.containerd.sandbox.store.v1.local type=io.containerd.sandbox.store.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023686616Z" level=info msg="loading plugin" id=io.containerd.cri.v1.images type=io.containerd.cri.v1 May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023749968Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\" for snapshotter \"overlayfs\"" May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023760008Z" level=info msg="Start snapshots syncer" May 15 11:58:37.024106 containerd[1875]: time="2025-05-15T11:58:37.023777360Z" level=info msg="loading plugin" id=io.containerd.cri.v1.runtime type=io.containerd.cri.v1 May 15 11:58:37.024220 containerd[1875]: time="2025-05-15T11:58:37.023926840Z" level=info msg="starting cri plugin" config="{\"containerd\":{\"defaultRuntimeName\":\"runc\",\"runtimes\":{\"runc\":{\"runtimeType\":\"io.containerd.runc.v2\",\"runtimePath\":\"\",\"PodAnnotations\":null,\"ContainerAnnotations\":null,\"options\":{\"BinaryName\":\"\",\"CriuImagePath\":\"\",\"CriuWorkPath\":\"\",\"IoGid\":0,\"IoUid\":0,\"NoNewKeyring\":false,\"Root\":\"\",\"ShimCgroup\":\"\",\"SystemdCgroup\":true},\"privileged_without_host_devices\":false,\"privileged_without_host_devices_all_devices_allowed\":false,\"baseRuntimeSpec\":\"\",\"cniConfDir\":\"\",\"cniMaxConfNum\":0,\"snapshotter\":\"\",\"sandboxer\":\"podsandbox\",\"io_type\":\"\"}},\"ignoreBlockIONotEnabledErrors\":false,\"ignoreRdtNotEnabledErrors\":false},\"cni\":{\"binDir\":\"/opt/cni/bin\",\"confDir\":\"/etc/cni/net.d\",\"maxConfNum\":1,\"setupSerially\":false,\"confTemplate\":\"\",\"ipPref\":\"\",\"useInternalLoopback\":false},\"enableSelinux\":true,\"selinuxCategoryRange\":1024,\"maxContainerLogSize\":16384,\"disableApparmor\":false,\"restrictOOMScoreAdj\":false,\"disableProcMount\":false,\"unsetSeccompProfile\":\"\",\"tolerateMissingHugetlbController\":true,\"disableHugetlbController\":true,\"device_ownership_from_security_context\":false,\"ignoreImageDefinedVolumes\":false,\"netnsMountsUnderStateDir\":false,\"enableUnprivilegedPorts\":true,\"enableUnprivilegedICMP\":true,\"enableCDI\":true,\"cdiSpecDirs\":[\"/etc/cdi\",\"/var/run/cdi\"],\"drainExecSyncIOTimeout\":\"0s\",\"ignoreDeprecationWarnings\":null,\"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\"}" May 15 11:58:37.024220 containerd[1875]: time="2025-05-15T11:58:37.023960080Z" level=info msg="loading plugin" id=io.containerd.podsandbox.controller.v1.podsandbox type=io.containerd.podsandbox.controller.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024015368Z" level=info msg="loading plugin" id=io.containerd.sandbox.controller.v1.shim type=io.containerd.sandbox.controller.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024112416Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandbox-controllers type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024127208Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandboxes type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024139008Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.snapshots type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024145144Z" level=info msg="loading plugin" id=io.containerd.streaming.v1.manager type=io.containerd.streaming.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024152136Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.streaming type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024158776Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.tasks type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024165008Z" level=info msg="loading plugin" id=io.containerd.transfer.v1.local type=io.containerd.transfer.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024183120Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.transfer type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024190056Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.version type=io.containerd.grpc.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024200488Z" level=info msg="loading plugin" id=io.containerd.monitor.container.v1.restart type=io.containerd.monitor.container.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024235240Z" level=info msg="loading plugin" id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024244208Z" level=info msg="skip loading plugin" error="skip plugin: tracing endpoint not configured" id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 May 15 11:58:37.024301 containerd[1875]: time="2025-05-15T11:58:37.024249608Z" level=info msg="loading plugin" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024255080Z" level=info msg="skip loading plugin" error="skip plugin: tracing endpoint not configured" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024259720Z" level=info msg="loading plugin" id=io.containerd.ttrpc.v1.otelttrpc type=io.containerd.ttrpc.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024266208Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.healthcheck type=io.containerd.grpc.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024273032Z" level=info msg="loading plugin" id=io.containerd.nri.v1.nri type=io.containerd.nri.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024287312Z" level=info msg="runtime interface created" May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024290472Z" level=info msg="created NRI interface" May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024297136Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.cri type=io.containerd.grpc.v1 May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024304064Z" level=info msg="Connect containerd service" May 15 11:58:37.024451 containerd[1875]: time="2025-05-15T11:58:37.024325272Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" May 15 11:58:37.025186 containerd[1875]: time="2025-05-15T11:58:37.024888448Z" 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" May 15 11:58:37.121283 kubelet[2016]: E0515 11:58:37.121240 2016 run.go:72] "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" May 15 11:58:37.123406 systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE May 15 11:58:37.123673 systemd[1]: kubelet.service: Failed with result 'exit-code'. May 15 11:58:37.124224 systemd[1]: kubelet.service: Consumed 501ms CPU time, 232.8M memory peak. May 15 11:58:37.725801 containerd[1875]: time="2025-05-15T11:58:37.725736808Z" level=info msg="Start subscribing containerd event" May 15 11:58:37.725801 containerd[1875]: time="2025-05-15T11:58:37.725803832Z" level=info msg="Start recovering state" May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725880584Z" level=info msg="Start event monitor" May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725891384Z" level=info msg="Start cni network conf syncer for default" May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725899888Z" level=info msg="Start streaming server" May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725906560Z" level=info msg="Registered namespace \"k8s.io\" with NRI" May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725911080Z" level=info msg="runtime interface starting up..." May 15 11:58:37.725915 containerd[1875]: time="2025-05-15T11:58:37.725914392Z" level=info msg="starting plugins..." May 15 11:58:37.726013 containerd[1875]: time="2025-05-15T11:58:37.725926160Z" level=info msg="Synchronizing NRI (plugin) with current runtime state" May 15 11:58:37.726027 containerd[1875]: time="2025-05-15T11:58:37.725768904Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc May 15 11:58:37.726061 containerd[1875]: time="2025-05-15T11:58:37.726046008Z" level=info msg=serving... address=/run/containerd/containerd.sock May 15 11:58:37.726216 systemd[1]: Started containerd.service - containerd container runtime. May 15 11:58:37.730969 containerd[1875]: time="2025-05-15T11:58:37.727780520Z" level=info msg="containerd successfully booted in 0.730004s" May 15 11:58:37.732450 systemd[1]: Reached target multi-user.target - Multi-User System. May 15 11:58:37.739493 systemd[1]: Startup finished in 1.674s (kernel) + 10.932s (initrd) + 11.991s (userspace) = 24.597s. May 15 11:58:38.222286 login[1998]: pam_lastlog(login:session): file /var/log/lastlog is locked/write, retrying May 15 11:58:38.223260 login[1999]: pam_unix(login:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:38.228267 systemd[1]: Created slice user-500.slice - User Slice of UID 500. May 15 11:58:38.229178 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... May 15 11:58:38.234457 systemd-logind[1852]: New session 1 of user core. May 15 11:58:38.241999 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. May 15 11:58:38.244522 systemd[1]: Starting user@500.service - User Manager for UID 500... May 15 11:58:38.253072 (systemd)[2049]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) May 15 11:58:38.254999 systemd-logind[1852]: New session c1 of user core. May 15 11:58:38.342271 waagent[1995]: 2025-05-15T11:58:38.342182Z INFO Daemon Daemon Azure Linux Agent Version: 2.12.0.4 May 15 11:58:38.350284 waagent[1995]: 2025-05-15T11:58:38.347235Z INFO Daemon Daemon OS: flatcar 4334.0.0 May 15 11:58:38.350543 waagent[1995]: 2025-05-15T11:58:38.350510Z INFO Daemon Daemon Python: 3.11.12 May 15 11:58:38.353944 waagent[1995]: 2025-05-15T11:58:38.353906Z INFO Daemon Daemon Run daemon May 15 11:58:38.357048 waagent[1995]: 2025-05-15T11:58:38.357016Z INFO Daemon Daemon No RDMA handler exists for distro='Flatcar Container Linux by Kinvolk' version='4334.0.0' May 15 11:58:38.363924 waagent[1995]: 2025-05-15T11:58:38.363892Z INFO Daemon Daemon Using waagent for provisioning May 15 11:58:38.367947 waagent[1995]: 2025-05-15T11:58:38.367914Z INFO Daemon Daemon Activate resource disk May 15 11:58:38.371757 waagent[1995]: 2025-05-15T11:58:38.371723Z INFO Daemon Daemon Searching gen1 prefix 00000000-0001 or gen2 f8b3781a-1e82-4818-a1c3-63d806ec15bb May 15 11:58:38.380186 waagent[1995]: 2025-05-15T11:58:38.380151Z INFO Daemon Daemon Found device: None May 15 11:58:38.383476 waagent[1995]: 2025-05-15T11:58:38.383448Z ERROR Daemon Daemon Failed to mount resource disk [ResourceDiskError] unable to detect disk topology May 15 11:58:38.389738 waagent[1995]: 2025-05-15T11:58:38.389709Z ERROR Daemon Daemon Event: name=WALinuxAgent, op=ActivateResourceDisk, message=[ResourceDiskError] unable to detect disk topology, duration=0 May 15 11:58:38.399998 waagent[1995]: 2025-05-15T11:58:38.399954Z INFO Daemon Daemon Clean protocol and wireserver endpoint May 15 11:58:38.404311 waagent[1995]: 2025-05-15T11:58:38.404275Z INFO Daemon Daemon Running default provisioning handler May 15 11:58:38.414018 waagent[1995]: 2025-05-15T11:58:38.413984Z INFO Daemon Daemon Unable to get cloud-init enabled status from systemctl: Command '['systemctl', 'is-enabled', 'cloud-init-local.service']' returned non-zero exit status 4. May 15 11:58:38.416801 systemd[2049]: Queued start job for default target default.target. May 15 11:58:38.424434 waagent[1995]: 2025-05-15T11:58:38.424403Z INFO Daemon Daemon Unable to get cloud-init enabled status from service: [Errno 2] No such file or directory: 'service' May 15 11:58:38.431744 waagent[1995]: 2025-05-15T11:58:38.431715Z INFO Daemon Daemon cloud-init is enabled: False May 15 11:58:38.432337 systemd[2049]: Created slice app.slice - User Application Slice. May 15 11:58:38.432361 systemd[2049]: Reached target paths.target - Paths. May 15 11:58:38.432729 systemd[2049]: Reached target timers.target - Timers. May 15 11:58:38.433795 systemd[2049]: Starting dbus.socket - D-Bus User Message Bus Socket... May 15 11:58:38.436231 waagent[1995]: 2025-05-15T11:58:38.436197Z INFO Daemon Daemon Copying ovf-env.xml May 15 11:58:38.441941 systemd[2049]: Listening on dbus.socket - D-Bus User Message Bus Socket. May 15 11:58:38.441983 systemd[2049]: Reached target sockets.target - Sockets. May 15 11:58:38.442013 systemd[2049]: Reached target basic.target - Basic System. May 15 11:58:38.442033 systemd[2049]: Reached target default.target - Main User Target. May 15 11:58:38.442050 systemd[2049]: Startup finished in 182ms. May 15 11:58:38.442164 systemd[1]: Started user@500.service - User Manager for UID 500. May 15 11:58:38.447702 systemd[1]: Started session-1.scope - Session 1 of User core. May 15 11:58:38.553012 waagent[1995]: 2025-05-15T11:58:38.550159Z INFO Daemon Daemon Successfully mounted dvd May 15 11:58:38.578987 systemd[1]: mnt-cdrom-secure.mount: Deactivated successfully. May 15 11:58:38.581664 waagent[1995]: 2025-05-15T11:58:38.581118Z INFO Daemon Daemon Detect protocol endpoint May 15 11:58:38.584947 waagent[1995]: 2025-05-15T11:58:38.584915Z INFO Daemon Daemon Clean protocol and wireserver endpoint May 15 11:58:38.589155 waagent[1995]: 2025-05-15T11:58:38.589127Z INFO Daemon Daemon WireServer endpoint is not found. Rerun dhcp handler May 15 11:58:38.594166 waagent[1995]: 2025-05-15T11:58:38.594143Z INFO Daemon Daemon Test for route to 168.63.129.16 May 15 11:58:38.598244 waagent[1995]: 2025-05-15T11:58:38.598215Z INFO Daemon Daemon Route to 168.63.129.16 exists May 15 11:58:38.602117 waagent[1995]: 2025-05-15T11:58:38.602084Z INFO Daemon Daemon Wire server endpoint:168.63.129.16 May 15 11:58:38.645345 waagent[1995]: 2025-05-15T11:58:38.645307Z INFO Daemon Daemon Fabric preferred wire protocol version:2015-04-05 May 15 11:58:38.650150 waagent[1995]: 2025-05-15T11:58:38.650128Z INFO Daemon Daemon Wire protocol version:2012-11-30 May 15 11:58:38.654010 waagent[1995]: 2025-05-15T11:58:38.653986Z INFO Daemon Daemon Server preferred version:2015-04-05 May 15 11:58:38.758811 waagent[1995]: 2025-05-15T11:58:38.758738Z INFO Daemon Daemon Initializing goal state during protocol detection May 15 11:58:38.763416 waagent[1995]: 2025-05-15T11:58:38.763386Z INFO Daemon Daemon Forcing an update of the goal state. May 15 11:58:38.775424 waagent[1995]: 2025-05-15T11:58:38.775393Z INFO Daemon Fetched a new incarnation for the WireServer goal state [incarnation 1] May 15 11:58:38.791560 waagent[1995]: 2025-05-15T11:58:38.791533Z INFO Daemon Daemon HostGAPlugin version: 1.0.8.164 May 15 11:58:38.795647 waagent[1995]: 2025-05-15T11:58:38.795621Z INFO Daemon May 15 11:58:38.797558 waagent[1995]: 2025-05-15T11:58:38.797533Z INFO Daemon Fetched new vmSettings [HostGAPlugin correlation ID: d03c3c9c-0526-43d9-9b20-4f096aa66887 eTag: 6374980197017842588 source: Fabric] May 15 11:58:38.805755 waagent[1995]: 2025-05-15T11:58:38.805698Z INFO Daemon The vmSettings originated via Fabric; will ignore them. May 15 11:58:38.810477 waagent[1995]: 2025-05-15T11:58:38.810452Z INFO Daemon May 15 11:58:38.812483 waagent[1995]: 2025-05-15T11:58:38.812461Z INFO Daemon Fetching full goal state from the WireServer [incarnation 1] May 15 11:58:38.822907 waagent[1995]: 2025-05-15T11:58:38.822883Z INFO Daemon Daemon Downloading artifacts profile blob May 15 11:58:38.894628 waagent[1995]: 2025-05-15T11:58:38.893799Z INFO Daemon Downloaded certificate {'thumbprint': 'E4E5828C252D696701CB0AD54E10A23B85B25644', 'hasPrivateKey': False} May 15 11:58:38.902694 waagent[1995]: 2025-05-15T11:58:38.902655Z INFO Daemon Downloaded certificate {'thumbprint': '9C7DB112171247567FF8E1E5294B4183D26D4512', 'hasPrivateKey': True} May 15 11:58:38.909730 waagent[1995]: 2025-05-15T11:58:38.909694Z INFO Daemon Fetch goal state completed May 15 11:58:38.919465 waagent[1995]: 2025-05-15T11:58:38.919434Z INFO Daemon Daemon Starting provisioning May 15 11:58:38.923291 waagent[1995]: 2025-05-15T11:58:38.923261Z INFO Daemon Daemon Handle ovf-env.xml. May 15 11:58:38.927621 waagent[1995]: 2025-05-15T11:58:38.927590Z INFO Daemon Daemon Set hostname [ci-4334.0.0-a-072134ebcf] May 15 11:58:38.954406 waagent[1995]: 2025-05-15T11:58:38.954354Z INFO Daemon Daemon Publish hostname [ci-4334.0.0-a-072134ebcf] May 15 11:58:38.959313 waagent[1995]: 2025-05-15T11:58:38.959275Z INFO Daemon Daemon Examine /proc/net/route for primary interface May 15 11:58:38.963928 waagent[1995]: 2025-05-15T11:58:38.963897Z INFO Daemon Daemon Primary interface is [eth0] May 15 11:58:38.973408 systemd-networkd[1482]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. May 15 11:58:38.973414 systemd-networkd[1482]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. May 15 11:58:38.973464 systemd-networkd[1482]: eth0: DHCP lease lost May 15 11:58:38.974430 waagent[1995]: 2025-05-15T11:58:38.974392Z INFO Daemon Daemon Create user account if not exists May 15 11:58:38.978556 waagent[1995]: 2025-05-15T11:58:38.978527Z INFO Daemon Daemon User core already exists, skip useradd May 15 11:58:38.982628 waagent[1995]: 2025-05-15T11:58:38.982600Z INFO Daemon Daemon Configure sudoer May 15 11:58:38.992637 waagent[1995]: 2025-05-15T11:58:38.992581Z INFO Daemon Daemon Configure sshd May 15 11:58:38.993661 systemd-networkd[1482]: eth0: DHCPv4 address 10.200.20.25/24, gateway 10.200.20.1 acquired from 168.63.129.16 May 15 11:58:39.002347 waagent[1995]: 2025-05-15T11:58:39.002306Z INFO Daemon Daemon Added a configuration snippet disabling SSH password-based authentication methods. It also configures SSH client probing to keep connections alive. May 15 11:58:39.012267 waagent[1995]: 2025-05-15T11:58:39.012233Z INFO Daemon Daemon Deploy ssh public key. May 15 11:58:39.223015 login[1998]: pam_unix(login:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:39.227421 systemd-logind[1852]: New session 2 of user core. May 15 11:58:39.236709 systemd[1]: Started session-2.scope - Session 2 of User core. May 15 11:58:40.090956 waagent[1995]: 2025-05-15T11:58:40.087804Z INFO Daemon Daemon Provisioning complete May 15 11:58:40.105101 waagent[1995]: 2025-05-15T11:58:40.105062Z INFO Daemon Daemon RDMA capabilities are not enabled, skipping May 15 11:58:40.109725 waagent[1995]: 2025-05-15T11:58:40.109691Z INFO Daemon Daemon End of log to /dev/console. The agent will now check for updates and then will process extensions. May 15 11:58:40.116751 waagent[1995]: 2025-05-15T11:58:40.116678Z INFO Daemon Daemon Installed Agent WALinuxAgent-2.12.0.4 is the most current agent May 15 11:58:40.210372 waagent[2101]: 2025-05-15T11:58:40.210312Z INFO ExtHandler ExtHandler Azure Linux Agent (Goal State Agent version 2.12.0.4) May 15 11:58:40.211059 waagent[2101]: 2025-05-15T11:58:40.210753Z INFO ExtHandler ExtHandler OS: flatcar 4334.0.0 May 15 11:58:40.211059 waagent[2101]: 2025-05-15T11:58:40.210806Z INFO ExtHandler ExtHandler Python: 3.11.12 May 15 11:58:40.211059 waagent[2101]: 2025-05-15T11:58:40.210841Z INFO ExtHandler ExtHandler CPU Arch: aarch64 May 15 11:58:40.246590 waagent[2101]: 2025-05-15T11:58:40.246540Z INFO ExtHandler ExtHandler Distro: flatcar-4334.0.0; OSUtil: FlatcarUtil; AgentService: waagent; Python: 3.11.12; Arch: aarch64; systemd: True; LISDrivers: Absent; logrotate: logrotate 3.22.0; May 15 11:58:40.246884 waagent[2101]: 2025-05-15T11:58:40.246853Z INFO ExtHandler ExtHandler WireServer endpoint 168.63.129.16 read from file May 15 11:58:40.246993 waagent[2101]: 2025-05-15T11:58:40.246970Z INFO ExtHandler ExtHandler Wire server endpoint:168.63.129.16 May 15 11:58:40.252900 waagent[2101]: 2025-05-15T11:58:40.252854Z INFO ExtHandler Fetched a new incarnation for the WireServer goal state [incarnation 1] May 15 11:58:40.282659 waagent[2101]: 2025-05-15T11:58:40.282579Z INFO ExtHandler ExtHandler HostGAPlugin version: 1.0.8.164 May 15 11:58:40.284265 waagent[2101]: 2025-05-15T11:58:40.283092Z INFO ExtHandler May 15 11:58:40.284265 waagent[2101]: 2025-05-15T11:58:40.283146Z INFO ExtHandler Fetched new vmSettings [HostGAPlugin correlation ID: 72cfafc7-ad22-479c-96a8-ef9c777473aa eTag: 6374980197017842588 source: Fabric] May 15 11:58:40.284265 waagent[2101]: 2025-05-15T11:58:40.283341Z INFO ExtHandler The vmSettings originated via Fabric; will ignore them. May 15 11:58:40.284265 waagent[2101]: 2025-05-15T11:58:40.283740Z INFO ExtHandler May 15 11:58:40.284265 waagent[2101]: 2025-05-15T11:58:40.283780Z INFO ExtHandler Fetching full goal state from the WireServer [incarnation 1] May 15 11:58:40.287879 waagent[2101]: 2025-05-15T11:58:40.287851Z INFO ExtHandler ExtHandler Downloading artifacts profile blob May 15 11:58:40.345872 waagent[2101]: 2025-05-15T11:58:40.345793Z INFO ExtHandler Downloaded certificate {'thumbprint': 'E4E5828C252D696701CB0AD54E10A23B85B25644', 'hasPrivateKey': False} May 15 11:58:40.346249 waagent[2101]: 2025-05-15T11:58:40.346221Z INFO ExtHandler Downloaded certificate {'thumbprint': '9C7DB112171247567FF8E1E5294B4183D26D4512', 'hasPrivateKey': True} May 15 11:58:40.346648 waagent[2101]: 2025-05-15T11:58:40.346615Z INFO ExtHandler Fetch goal state completed May 15 11:58:40.357314 waagent[2101]: 2025-05-15T11:58:40.357283Z INFO ExtHandler ExtHandler OpenSSL version: OpenSSL 3.3.3 11 Feb 2025 (Library: OpenSSL 3.3.3 11 Feb 2025) May 15 11:58:40.360503 waagent[2101]: 2025-05-15T11:58:40.360469Z INFO ExtHandler ExtHandler WALinuxAgent-2.12.0.4 running as process 2101 May 15 11:58:40.360698 waagent[2101]: 2025-05-15T11:58:40.360671Z INFO ExtHandler ExtHandler ******** AutoUpdate.Enabled is set to False, not processing the operation ******** May 15 11:58:40.361004 waagent[2101]: 2025-05-15T11:58:40.360976Z INFO ExtHandler ExtHandler ******** AutoUpdate.UpdateToLatestVersion is set to False, not processing the operation ******** May 15 11:58:40.362164 waagent[2101]: 2025-05-15T11:58:40.362130Z INFO ExtHandler ExtHandler [CGI] Cgroup monitoring is not supported on ['flatcar', '4334.0.0', '', 'Flatcar Container Linux by Kinvolk'] May 15 11:58:40.362557 waagent[2101]: 2025-05-15T11:58:40.362526Z INFO ExtHandler ExtHandler [CGI] Agent will reset the quotas in case distro: ['flatcar', '4334.0.0', '', 'Flatcar Container Linux by Kinvolk'] went from supported to unsupported May 15 11:58:40.362762 waagent[2101]: 2025-05-15T11:58:40.362735Z INFO ExtHandler ExtHandler [CGI] Agent cgroups enabled: False May 15 11:58:40.363267 waagent[2101]: 2025-05-15T11:58:40.363235Z INFO ExtHandler ExtHandler Starting setup for Persistent firewall rules May 15 11:58:40.381555 waagent[2101]: 2025-05-15T11:58:40.381529Z INFO ExtHandler ExtHandler Firewalld service not running/unavailable, trying to set up waagent-network-setup.service May 15 11:58:40.381779 waagent[2101]: 2025-05-15T11:58:40.381750Z INFO ExtHandler ExtHandler Successfully updated the Binary file /var/lib/waagent/waagent-network-setup.py for firewall setup May 15 11:58:40.386030 waagent[2101]: 2025-05-15T11:58:40.386009Z INFO ExtHandler ExtHandler Service: waagent-network-setup.service not enabled. Adding it now May 15 11:58:40.402592 systemd[1]: Reload requested from client PID 2118 ('systemctl') (unit waagent.service)... May 15 11:58:40.402622 systemd[1]: Reloading... May 15 11:58:40.468781 zram_generator::config[2155]: No configuration found. May 15 11:58:40.537670 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. May 15 11:58:40.616329 systemd[1]: Reloading finished in 213 ms. May 15 11:58:40.628868 waagent[2101]: 2025-05-15T11:58:40.626643Z INFO ExtHandler ExtHandler Successfully added and enabled the waagent-network-setup.service May 15 11:58:40.628868 waagent[2101]: 2025-05-15T11:58:40.626779Z INFO ExtHandler ExtHandler Persistent firewall rules setup successfully May 15 11:58:40.931733 waagent[2101]: 2025-05-15T11:58:40.931582Z INFO ExtHandler ExtHandler DROP rule is not available which implies no firewall rules are set yet. Environment thread will set it up. May 15 11:58:40.931952 waagent[2101]: 2025-05-15T11:58:40.931920Z INFO ExtHandler ExtHandler Checking if log collection is allowed at this time [False]. All three conditions must be met: 1. configuration enabled [True], 2. cgroups v1 enabled [False] OR cgroups v2 is in use and v2 resource limiting configuration enabled [False], 3. python supported: [True] May 15 11:58:40.932571 waagent[2101]: 2025-05-15T11:58:40.932529Z INFO ExtHandler ExtHandler Starting env monitor service. May 15 11:58:40.932878 waagent[2101]: 2025-05-15T11:58:40.932836Z INFO ExtHandler ExtHandler Start SendTelemetryHandler service. May 15 11:58:40.933066 waagent[2101]: 2025-05-15T11:58:40.933032Z INFO EnvHandler ExtHandler WireServer endpoint 168.63.129.16 read from file May 15 11:58:40.933620 waagent[2101]: 2025-05-15T11:58:40.933244Z INFO MonitorHandler ExtHandler WireServer endpoint 168.63.129.16 read from file May 15 11:58:40.933620 waagent[2101]: 2025-05-15T11:58:40.933306Z INFO MonitorHandler ExtHandler Wire server endpoint:168.63.129.16 May 15 11:58:40.933620 waagent[2101]: 2025-05-15T11:58:40.933466Z INFO MonitorHandler ExtHandler Monitor.NetworkConfigurationChanges is disabled. May 15 11:58:40.933846 waagent[2101]: 2025-05-15T11:58:40.933812Z INFO SendTelemetryHandler ExtHandler Successfully started the SendTelemetryHandler thread May 15 11:58:40.933886 waagent[2101]: 2025-05-15T11:58:40.933844Z INFO ExtHandler ExtHandler Start Extension Telemetry service. May 15 11:58:40.933928 waagent[2101]: 2025-05-15T11:58:40.933748Z INFO MonitorHandler ExtHandler Routing table from /proc/net/route: May 15 11:58:40.933928 waagent[2101]: Iface Destination Gateway Flags RefCnt Use Metric Mask MTU Window IRTT May 15 11:58:40.933928 waagent[2101]: eth0 00000000 0114C80A 0003 0 0 1024 00000000 0 0 0 May 15 11:58:40.933928 waagent[2101]: eth0 0014C80A 00000000 0001 0 0 1024 00FFFFFF 0 0 0 May 15 11:58:40.933928 waagent[2101]: eth0 0114C80A 00000000 0005 0 0 1024 FFFFFFFF 0 0 0 May 15 11:58:40.933928 waagent[2101]: eth0 10813FA8 0114C80A 0007 0 0 1024 FFFFFFFF 0 0 0 May 15 11:58:40.933928 waagent[2101]: eth0 FEA9FEA9 0114C80A 0007 0 0 1024 FFFFFFFF 0 0 0 May 15 11:58:40.934064 waagent[2101]: 2025-05-15T11:58:40.934032Z INFO TelemetryEventsCollector ExtHandler Extension Telemetry pipeline enabled: True May 15 11:58:40.934209 waagent[2101]: 2025-05-15T11:58:40.934186Z INFO ExtHandler ExtHandler Goal State Period: 6 sec. This indicates how often the agent checks for new goal states and reports status. May 15 11:58:40.934394 waagent[2101]: 2025-05-15T11:58:40.934350Z INFO EnvHandler ExtHandler Wire server endpoint:168.63.129.16 May 15 11:58:40.934443 waagent[2101]: 2025-05-15T11:58:40.934411Z INFO TelemetryEventsCollector ExtHandler Successfully started the TelemetryEventsCollector thread May 15 11:58:40.935036 waagent[2101]: 2025-05-15T11:58:40.934985Z INFO EnvHandler ExtHandler Configure routes May 15 11:58:40.935947 waagent[2101]: 2025-05-15T11:58:40.935757Z INFO EnvHandler ExtHandler Gateway:None May 15 11:58:40.935947 waagent[2101]: 2025-05-15T11:58:40.935836Z INFO EnvHandler ExtHandler Routes:None May 15 11:58:40.941579 waagent[2101]: 2025-05-15T11:58:40.941545Z INFO ExtHandler ExtHandler May 15 11:58:40.941716 waagent[2101]: 2025-05-15T11:58:40.941691Z INFO ExtHandler ExtHandler ProcessExtensionsGoalState started [incarnation_1 channel: WireServer source: Fabric activity: 89390b4c-4664-4116-b8ff-aa935e6017e4 correlation 058efa36-aa02-47c9-ae3b-6e3e272190be created: 2025-05-15T11:57:27.589233Z] May 15 11:58:40.942064 waagent[2101]: 2025-05-15T11:58:40.942034Z INFO ExtHandler ExtHandler No extension handlers found, not processing anything. May 15 11:58:40.942540 waagent[2101]: 2025-05-15T11:58:40.942511Z INFO ExtHandler ExtHandler ProcessExtensionsGoalState completed [incarnation_1 0 ms] May 15 11:58:40.973534 waagent[2101]: 2025-05-15T11:58:40.973481Z WARNING ExtHandler ExtHandler Failed to get firewall packets: 'iptables -w -t security -L OUTPUT --zero OUTPUT -nxv' failed: 2 (iptables v1.8.11 (nf_tables): Illegal option `--numeric' with this command May 15 11:58:40.973534 waagent[2101]: Try `iptables -h' or 'iptables --help' for more information.) May 15 11:58:40.973872 waagent[2101]: 2025-05-15T11:58:40.973840Z INFO ExtHandler ExtHandler [HEARTBEAT] Agent WALinuxAgent-2.12.0.4 is running as the goal state agent [DEBUG HeartbeatCounter: 0;HeartbeatId: C005F182-3793-406B-BB04-7FB8ECE603DD;DroppedPackets: -1;UpdateGSErrors: 0;AutoUpdate: 0;UpdateMode: SelfUpdate;] May 15 11:58:40.991626 waagent[2101]: 2025-05-15T11:58:40.991335Z INFO MonitorHandler ExtHandler Network interfaces: May 15 11:58:40.991626 waagent[2101]: Executing ['ip', '-a', '-o', 'link']: May 15 11:58:40.991626 waagent[2101]: 1: lo: mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000\ link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 May 15 11:58:40.991626 waagent[2101]: 2: eth0: mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000\ link/ether 00:22:48:76:ff:fc brd ff:ff:ff:ff:ff:ff May 15 11:58:40.991626 waagent[2101]: 3: enP22304s1: mtu 1500 qdisc mq master eth0 state UP mode DEFAULT group default qlen 1000\ link/ether 00:22:48:76:ff:fc brd ff:ff:ff:ff:ff:ff\ altname enP22304p0s2 May 15 11:58:40.991626 waagent[2101]: Executing ['ip', '-4', '-a', '-o', 'address']: May 15 11:58:40.991626 waagent[2101]: 1: lo inet 127.0.0.1/8 scope host lo\ valid_lft forever preferred_lft forever May 15 11:58:40.991626 waagent[2101]: 2: eth0 inet 10.200.20.25/24 metric 1024 brd 10.200.20.255 scope global eth0\ valid_lft forever preferred_lft forever May 15 11:58:40.991626 waagent[2101]: Executing ['ip', '-6', '-a', '-o', 'address']: May 15 11:58:40.991626 waagent[2101]: 1: lo inet6 ::1/128 scope host noprefixroute \ valid_lft forever preferred_lft forever May 15 11:58:40.991626 waagent[2101]: 2: eth0 inet6 fe80::222:48ff:fe76:fffc/64 scope link proto kernel_ll \ valid_lft forever preferred_lft forever May 15 11:58:40.991626 waagent[2101]: 3: enP22304s1 inet6 fe80::222:48ff:fe76:fffc/64 scope link proto kernel_ll \ valid_lft forever preferred_lft forever May 15 11:58:41.023415 waagent[2101]: 2025-05-15T11:58:41.023371Z INFO EnvHandler ExtHandler Created firewall rules for the Azure Fabric: May 15 11:58:41.023415 waagent[2101]: Chain INPUT (policy ACCEPT 0 packets, 0 bytes) May 15 11:58:41.023415 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.023415 waagent[2101]: Chain FORWARD (policy ACCEPT 0 packets, 0 bytes) May 15 11:58:41.023415 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.023415 waagent[2101]: Chain OUTPUT (policy ACCEPT 6 packets, 888 bytes) May 15 11:58:41.023415 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.023415 waagent[2101]: 0 0 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 tcp dpt:53 May 15 11:58:41.023415 waagent[2101]: 1 52 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 owner UID match 0 May 15 11:58:41.023415 waagent[2101]: 0 0 DROP tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW May 15 11:58:41.027094 waagent[2101]: 2025-05-15T11:58:41.027052Z INFO EnvHandler ExtHandler Current Firewall rules: May 15 11:58:41.027094 waagent[2101]: Chain INPUT (policy ACCEPT 0 packets, 0 bytes) May 15 11:58:41.027094 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.027094 waagent[2101]: Chain FORWARD (policy ACCEPT 0 packets, 0 bytes) May 15 11:58:41.027094 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.027094 waagent[2101]: Chain OUTPUT (policy ACCEPT 6 packets, 888 bytes) May 15 11:58:41.027094 waagent[2101]: pkts bytes target prot opt in out source destination May 15 11:58:41.027094 waagent[2101]: 0 0 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 tcp dpt:53 May 15 11:58:41.027094 waagent[2101]: 4 416 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 owner UID match 0 May 15 11:58:41.027094 waagent[2101]: 0 0 DROP tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW May 15 11:58:41.027556 waagent[2101]: 2025-05-15T11:58:41.027532Z INFO EnvHandler ExtHandler Set block dev timeout: sda with timeout: 300 May 15 11:58:44.439570 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. May 15 11:58:44.441298 systemd[1]: Started sshd@0-10.200.20.25:22-10.200.16.10:48106.service - OpenSSH per-connection server daemon (10.200.16.10:48106). May 15 11:58:44.990792 sshd[2243]: Accepted publickey for core from 10.200.16.10 port 48106 ssh2: RSA SHA256:eqZH8i+mbXa4bcBb58m8yxDt9xvP66g2WQqbkjlQjHI May 15 11:58:44.991863 sshd-session[2243]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:44.995399 systemd-logind[1852]: New session 3 of user core. May 15 11:58:45.003703 systemd[1]: Started session-3.scope - Session 3 of User core. May 15 11:58:45.396127 systemd[1]: Started sshd@1-10.200.20.25:22-10.200.16.10:48122.service - OpenSSH per-connection server daemon (10.200.16.10:48122). May 15 11:58:45.818069 sshd[2248]: Accepted publickey for core from 10.200.16.10 port 48122 ssh2: RSA SHA256:eqZH8i+mbXa4bcBb58m8yxDt9xvP66g2WQqbkjlQjHI May 15 11:58:45.818987 sshd-session[2248]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:45.822439 systemd-logind[1852]: New session 4 of user core. May 15 11:58:45.830862 systemd[1]: Started session-4.scope - Session 4 of User core. May 15 11:58:46.145330 sshd[2250]: Connection closed by 10.200.16.10 port 48122 May 15 11:58:46.145165 sshd-session[2248]: pam_unix(sshd:session): session closed for user core May 15 11:58:46.148324 systemd[1]: sshd@1-10.200.20.25:22-10.200.16.10:48122.service: Deactivated successfully. May 15 11:58:46.149794 systemd[1]: session-4.scope: Deactivated successfully. May 15 11:58:46.150534 systemd-logind[1852]: Session 4 logged out. Waiting for processes to exit. May 15 11:58:46.152034 systemd-logind[1852]: Removed session 4. May 15 11:58:46.221348 systemd[1]: Started sshd@2-10.200.20.25:22-10.200.16.10:48130.service - OpenSSH per-connection server daemon (10.200.16.10:48130). May 15 11:58:46.643614 sshd[2256]: Accepted publickey for core from 10.200.16.10 port 48130 ssh2: RSA SHA256:eqZH8i+mbXa4bcBb58m8yxDt9xvP66g2WQqbkjlQjHI May 15 11:58:46.644513 sshd-session[2256]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:46.648036 systemd-logind[1852]: New session 5 of user core. May 15 11:58:46.656717 systemd[1]: Started session-5.scope - Session 5 of User core. May 15 11:58:46.970097 sshd[2258]: Connection closed by 10.200.16.10 port 48130 May 15 11:58:46.969460 sshd-session[2256]: pam_unix(sshd:session): session closed for user core May 15 11:58:46.972173 systemd[1]: sshd@2-10.200.20.25:22-10.200.16.10:48130.service: Deactivated successfully. May 15 11:58:46.973588 systemd[1]: session-5.scope: Deactivated successfully. May 15 11:58:46.974757 systemd-logind[1852]: Session 5 logged out. Waiting for processes to exit. May 15 11:58:46.976516 systemd-logind[1852]: Removed session 5. May 15 11:58:47.048339 systemd[1]: Started sshd@3-10.200.20.25:22-10.200.16.10:48140.service - OpenSSH per-connection server daemon (10.200.16.10:48140). May 15 11:58:47.374293 systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 1. May 15 11:58:47.376119 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... May 15 11:58:47.459632 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent. May 15 11:58:47.462089 (kubelet)[2274]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_EXTRA_ARGS, KUBELET_KUBEADM_ARGS May 15 11:58:47.470126 sshd[2264]: Accepted publickey for core from 10.200.16.10 port 48140 ssh2: RSA SHA256:eqZH8i+mbXa4bcBb58m8yxDt9xvP66g2WQqbkjlQjHI May 15 11:58:47.471524 sshd-session[2264]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:47.475194 systemd-logind[1852]: New session 6 of user core. May 15 11:58:47.482709 systemd[1]: Started session-6.scope - Session 6 of User core. May 15 11:58:47.550384 kubelet[2274]: E0515 11:58:47.550306 2274 run.go:72] "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" May 15 11:58:47.553175 systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE May 15 11:58:47.553285 systemd[1]: kubelet.service: Failed with result 'exit-code'. May 15 11:58:47.553755 systemd[1]: kubelet.service: Consumed 101ms CPU time, 95.5M memory peak. May 15 11:58:47.795648 sshd[2279]: Connection closed by 10.200.16.10 port 48140 May 15 11:58:47.795014 sshd-session[2264]: pam_unix(sshd:session): session closed for user core May 15 11:58:47.798129 systemd-logind[1852]: Session 6 logged out. Waiting for processes to exit. May 15 11:58:47.798696 systemd[1]: sshd@3-10.200.20.25:22-10.200.16.10:48140.service: Deactivated successfully. May 15 11:58:47.799981 systemd[1]: session-6.scope: Deactivated successfully. May 15 11:58:47.802658 systemd-logind[1852]: Removed session 6. May 15 11:58:47.875802 systemd[1]: Started sshd@4-10.200.20.25:22-10.200.16.10:48152.service - OpenSSH per-connection server daemon (10.200.16.10:48152). May 15 11:58:48.327932 sshd[2287]: Accepted publickey for core from 10.200.16.10 port 48152 ssh2: RSA SHA256:eqZH8i+mbXa4bcBb58m8yxDt9xvP66g2WQqbkjlQjHI May 15 11:58:48.328974 sshd-session[2287]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) May 15 11:58:48.332548 systemd-logind[1852]: New session 7 of user core. May 15 11:58:48.342885 systemd[1]: Started session-7.scope - Session 7 of User core. May 15 11:58:48.697766 sudo[2290]: core : PWD=/home/core ; USER=root ; COMMAND=/home/core/install.sh May 15 11:58:48.698003 sudo[2290]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) May 15 11:58:48.956163 systemd[1]: Stopped kubelet.service - kubelet: The Kubernetes Node Agent. May 15 11:58:48.956582 systemd[1]: kubelet.service: Consumed 101ms CPU time, 95.5M memory peak. May 15 11:58:48.958290 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... May 15 11:58:48.979190 systemd[1]: Reload requested from client PID 2321 ('systemctl') (unit session-7.scope)... May 15 11:58:48.979201 systemd[1]: Reloading... May 15 11:58:49.074648 zram_generator::config[2377]: No configuration found. May 15 11:58:49.132159 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. May 15 11:58:49.210006 systemd[1]: Reloading finished in 230 ms. May 15 11:58:49.257658 systemd[1]: Stopping kubelet.service - kubelet: The Kubernetes Node Agent... May 15 11:58:49.258674 systemd[1]: kubelet.service: Deactivated successfully. May 15 11:58:49.259706 systemd[1]: Stopped kubelet.service - kubelet: The Kubernetes Node Agent. May 15 11:58:49.259750 systemd[1]: kubelet.service: Consumed 68ms CPU time, 82.5M memory peak. May 15 11:58:49.260846 systemd[1]: Starting kubelet.service - kubelet: The Kubernetes Node Agent... May 15 11:58:49.415676 systemd[1]: Started kubelet.service - kubelet: The Kubernetes Node Agent. May 15 11:58:49.427850 (kubelet)[2434]: kubelet.service: Referenced but unset environment variable evaluates to an empty string: KUBELET_EXTRA_ARGS May 15 11:58:49.544974 kubelet[2434]: 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. May 15 11:58:49.544974 kubelet[2434]: 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. May 15 11:58:49.544974 kubelet[2434]: 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. May 15 11:58:49.544974 kubelet[2434]: I0515 11:58:49.543857 2434 server.go:206] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime" May 15 11:58:49.913188 kubelet[2434]: I0515 11:58:49.913091 2434 server.go:486] "Kubelet version" kubeletVersion="v1.31.0" May 15 11:58:49.913188 kubelet[2434]: I0515 11:58:49.913122 2434 server.go:488] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK="" May 15 11:58:49.913410 kubelet[2434]: I0515 11:58:49.913390 2434 server.go:929] "Client rotation is on, will bootstrap in background" May 15 11:58:49.929909 kubelet[2434]: I0515 11:58:49.929686 2434 dynamic_cafile_content.go:160] "Starting controller" name="client-ca-bundle::/etc/kubernetes/pki/ca.crt" May 15 11:58:49.935528 kubelet[2434]: I0515 11:58:49.935495 2434 server.go:1426] "Using cgroup driver setting received from the CRI runtime" cgroupDriver="systemd" May 15 11:58:49.939192 kubelet[2434]: I0515 11:58:49.939168 2434 server.go:744] "--cgroups-per-qos enabled, but --cgroup-root was not specified. defaulting to /" May 15 11:58:49.939647 kubelet[2434]: I0515 11:58:49.939628 2434 swap_util.go:113] "Swap is on" /proc/swaps contents="Filename\t\t\t\tType\t\tSize\t\tUsed\t\tPriority" May 15 11:58:49.939775 kubelet[2434]: I0515 11:58:49.939754 2434 container_manager_linux.go:264] "Container manager verified user specified cgroup-root exists" cgroupRoot=[] May 15 11:58:49.939892 kubelet[2434]: I0515 11:58:49.939774 2434 container_manager_linux.go:269] "Creating Container Manager object based on Node Config" nodeConfig={"NodeName":"10.200.20.25","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":"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},{"Signal":"imagefs.inodesFree","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"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}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"ExperimentalMemoryManagerPolicy":"None","ExperimentalMemoryManagerReservedMemory":null,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null,"CgroupVersion":2} May 15 11:58:49.939976 kubelet[2434]: I0515 11:58:49.939900 2434 topology_manager.go:138] "Creating topology manager with none policy" May 15 11:58:49.939976 kubelet[2434]: I0515 11:58:49.939907 2434 container_manager_linux.go:300] "Creating device plugin manager" May 15 11:58:49.940028 kubelet[2434]: I0515 11:58:49.940017 2434 state_mem.go:36] "Initialized new in-memory state store" May 15 11:58:49.940720 kubelet[2434]: I0515 11:58:49.940699 2434 kubelet.go:408] "Attempting to sync node with API server" May 15 11:58:49.940720 kubelet[2434]: I0515 11:58:49.940719 2434 kubelet.go:303] "Adding static pod path" path="/etc/kubernetes/manifests" May 15 11:58:49.940797 kubelet[2434]: I0515 11:58:49.940739 2434 kubelet.go:314] "Adding apiserver pod source" May 15 11:58:49.940797 kubelet[2434]: I0515 11:58:49.940750 2434 apiserver.go:42] "Waiting for node sync before watching apiserver pods" May 15 11:58:49.941085 kubelet[2434]: E0515 11:58:49.941064 2434 file.go:98] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:49.941182 kubelet[2434]: E0515 11:58:49.941170 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:49.942556 kubelet[2434]: I0515 11:58:49.942415 2434 kuberuntime_manager.go:262] "Container runtime initialized" containerRuntime="containerd" version="v2.0.4" apiVersion="v1" May 15 11:58:49.944086 kubelet[2434]: I0515 11:58:49.943640 2434 kubelet.go:837] "Not starting ClusterTrustBundle informer because we are in static kubelet mode" May 15 11:58:49.944086 kubelet[2434]: W0515 11:58:49.943707 2434 probe.go:272] Flexvolume plugin directory at /opt/libexec/kubernetes/kubelet-plugins/volume/exec/ does not exist. Recreating. May 15 11:58:49.944171 kubelet[2434]: I0515 11:58:49.944119 2434 server.go:1269] "Started kubelet" May 15 11:58:49.944583 kubelet[2434]: I0515 11:58:49.944560 2434 server.go:163] "Starting to listen" address="0.0.0.0" port=10250 May 15 11:58:49.945331 kubelet[2434]: I0515 11:58:49.945312 2434 server.go:460] "Adding debug handlers to kubelet server" May 15 11:58:49.946157 kubelet[2434]: I0515 11:58:49.946116 2434 ratelimit.go:55] "Setting rate limiting for endpoint" service="podresources" qps=100 burstTokens=10 May 15 11:58:49.946383 kubelet[2434]: I0515 11:58:49.946364 2434 server.go:236] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock" May 15 11:58:49.947102 kubelet[2434]: W0515 11:58:49.947070 2434 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Node: nodes "10.200.20.25" is forbidden: User "system:anonymous" cannot list resource "nodes" in API group "" at the cluster scope May 15 11:58:49.947155 kubelet[2434]: E0515 11:58:49.947105 2434 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: Failed to watch *v1.Node: failed to list *v1.Node: nodes \"10.200.20.25\" is forbidden: User \"system:anonymous\" cannot list resource \"nodes\" in API group \"\" at the cluster scope" logger="UnhandledError" May 15 11:58:49.947885 kubelet[2434]: W0515 11:58:49.947860 2434 reflector.go:561] k8s.io/client-go/informers/factory.go:160: failed to list *v1.Service: services is forbidden: User "system:anonymous" cannot list resource "services" in API group "" at the cluster scope May 15 11:58:49.947941 kubelet[2434]: E0515 11:58:49.947890 2434 reflector.go:158] "Unhandled Error" err="k8s.io/client-go/informers/factory.go:160: 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" logger="UnhandledError" May 15 11:58:49.947989 kubelet[2434]: I0515 11:58:49.947977 2434 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer" May 15 11:58:49.949974 kubelet[2434]: E0515 11:58:49.949942 2434 kubelet.go:1478] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem" May 15 11:58:49.950832 kubelet[2434]: I0515 11:58:49.950808 2434 dynamic_serving_content.go:135] "Starting controller" name="kubelet-server-cert-files::/var/lib/kubelet/pki/kubelet.crt::/var/lib/kubelet/pki/kubelet.key" May 15 11:58:49.954259 kubelet[2434]: I0515 11:58:49.954241 2434 volume_manager.go:289] "Starting Kubelet Volume Manager" May 15 11:58:49.955211 kubelet[2434]: E0515 11:58:49.953573 2434 event.go:359] "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.200.20.25.183fb17cc8b05770 default 0 0001-01-01 00:00:00 +0000 UTC map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Node,Namespace:,Name:10.200.20.25,UID:10.200.20.25,APIVersion:,ResourceVersion:,FieldPath:,},Reason:Starting,Message:Starting kubelet.,Source:EventSource{Component:kubelet,Host:10.200.20.25,},FirstTimestamp:2025-05-15 11:58:49.944102768 +0000 UTC m=+0.513891057,LastTimestamp:2025-05-15 11:58:49.944102768 +0000 UTC m=+0.513891057,Count:1,Type:Normal,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:10.200.20.25,}" May 15 11:58:49.955466 kubelet[2434]: E0515 11:58:49.955440 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:49.956185 kubelet[2434]: I0515 11:58:49.956162 2434 factory.go:221] Registration of the systemd container factory successfully May 15 11:58:49.956260 kubelet[2434]: I0515 11:58:49.956244 2434 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 May 15 11:58:49.956895 kubelet[2434]: I0515 11:58:49.956880 2434 desired_state_of_world_populator.go:146] "Desired state populator starts to run" May 15 11:58:49.957021 kubelet[2434]: I0515 11:58:49.957012 2434 reconciler.go:26] "Reconciler: start to sync state" May 15 11:58:49.958239 kubelet[2434]: I0515 11:58:49.958211 2434 factory.go:221] Registration of the containerd container factory successfully May 15 11:58:49.974788 kubelet[2434]: I0515 11:58:49.974770 2434 cpu_manager.go:214] "Starting CPU manager" policy="none" May 15 11:58:49.975119 kubelet[2434]: I0515 11:58:49.974905 2434 cpu_manager.go:215] "Reconciling" reconcilePeriod="10s" May 15 11:58:49.975119 kubelet[2434]: I0515 11:58:49.974926 2434 state_mem.go:36] "Initialized new in-memory state store" May 15 11:58:49.975119 kubelet[2434]: E0515 11:58:49.975026 2434 nodelease.go:49] "Failed to get node when trying to set owner ref to the node lease" err="nodes \"10.200.20.25\" not found" node="10.200.20.25" May 15 11:58:49.989925 kubelet[2434]: I0515 11:58:49.989903 2434 policy_none.go:49] "None policy: Start" May 15 11:58:49.990570 kubelet[2434]: I0515 11:58:49.990557 2434 memory_manager.go:170] "Starting memorymanager" policy="None" May 15 11:58:49.990677 kubelet[2434]: I0515 11:58:49.990668 2434 state_mem.go:35] "Initializing new in-memory state store" May 15 11:58:49.999157 systemd[1]: Created slice kubepods.slice - libcontainer container kubepods.slice. May 15 11:58:50.009840 systemd[1]: Created slice kubepods-burstable.slice - libcontainer container kubepods-burstable.slice. May 15 11:58:50.012585 systemd[1]: Created slice kubepods-besteffort.slice - libcontainer container kubepods-besteffort.slice. May 15 11:58:50.020120 kubelet[2434]: I0515 11:58:50.020102 2434 manager.go:510] "Failed to read data from checkpoint" checkpoint="kubelet_internal_checkpoint" err="checkpoint is not found" May 15 11:58:50.020783 kubelet[2434]: I0515 11:58:50.020351 2434 eviction_manager.go:189] "Eviction manager: starting control loop" May 15 11:58:50.020783 kubelet[2434]: I0515 11:58:50.020364 2434 container_log_manager.go:189] "Initializing container log rotate workers" workers=1 monitorPeriod="10s" May 15 11:58:50.020783 kubelet[2434]: I0515 11:58:50.020569 2434 plugin_manager.go:118] "Starting Kubelet Plugin Manager" May 15 11:58:50.021783 kubelet[2434]: E0515 11:58:50.021746 2434 eviction_manager.go:285] "Eviction manager: failed to get summary stats" err="failed to get node info: node \"10.200.20.25\" not found" May 15 11:58:50.029209 kubelet[2434]: I0515 11:58:50.029179 2434 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv4" May 15 11:58:50.030094 kubelet[2434]: I0515 11:58:50.030077 2434 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv6" May 15 11:58:50.030164 kubelet[2434]: I0515 11:58:50.030154 2434 status_manager.go:217] "Starting to sync pod status with apiserver" May 15 11:58:50.030228 kubelet[2434]: I0515 11:58:50.030222 2434 kubelet.go:2321] "Starting kubelet main sync loop" May 15 11:58:50.030297 kubelet[2434]: E0515 11:58:50.030288 2434 kubelet.go:2345] "Skipping pod synchronization" err="PLEG is not healthy: pleg has yet to be successful" May 15 11:58:50.122730 kubelet[2434]: I0515 11:58:50.122240 2434 kubelet_node_status.go:72] "Attempting to register node" node="10.200.20.25" May 15 11:58:50.126256 kubelet[2434]: I0515 11:58:50.126236 2434 kubelet_node_status.go:75] "Successfully registered node" node="10.200.20.25" May 15 11:58:50.126319 kubelet[2434]: E0515 11:58:50.126261 2434 kubelet_node_status.go:535] "Error updating node status, will retry" err="error getting node \"10.200.20.25\": node \"10.200.20.25\" not found" May 15 11:58:50.145846 kubelet[2434]: E0515 11:58:50.145815 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.246976 kubelet[2434]: E0515 11:58:50.246759 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.347638 kubelet[2434]: E0515 11:58:50.347580 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.443893 sudo[2290]: pam_unix(sudo:session): session closed for user root May 15 11:58:50.448162 kubelet[2434]: E0515 11:58:50.448131 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.513906 sshd[2289]: Connection closed by 10.200.16.10 port 48152 May 15 11:58:50.513760 sshd-session[2287]: pam_unix(sshd:session): session closed for user core May 15 11:58:50.516219 systemd[1]: sshd@4-10.200.20.25:22-10.200.16.10:48152.service: Deactivated successfully. May 15 11:58:50.517782 systemd[1]: session-7.scope: Deactivated successfully. May 15 11:58:50.517994 systemd[1]: session-7.scope: Consumed 251ms CPU time, 71.5M memory peak. May 15 11:58:50.519416 systemd-logind[1852]: Session 7 logged out. Waiting for processes to exit. May 15 11:58:50.520835 systemd-logind[1852]: Removed session 7. May 15 11:58:50.548637 kubelet[2434]: E0515 11:58:50.548609 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.649069 kubelet[2434]: E0515 11:58:50.649033 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.749424 kubelet[2434]: E0515 11:58:50.749384 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.850248 kubelet[2434]: E0515 11:58:50.850131 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:50.916668 kubelet[2434]: I0515 11:58:50.916622 2434 transport.go:147] "Certificate rotation detected, shutting down client connections to start using new credentials" May 15 11:58:50.917072 kubelet[2434]: W0515 11:58:50.916989 2434 reflector.go:484] k8s.io/client-go/informers/factory.go:160: watch of *v1.RuntimeClass ended with: very short watch: k8s.io/client-go/informers/factory.go:160: Unexpected watch close - watch lasted less than a second and no items received May 15 11:58:50.917160 kubelet[2434]: W0515 11:58:50.917145 2434 reflector.go:484] k8s.io/client-go/informers/factory.go:160: watch of *v1.CSIDriver ended with: very short watch: k8s.io/client-go/informers/factory.go:160: Unexpected watch close - watch lasted less than a second and no items received May 15 11:58:50.941923 kubelet[2434]: E0515 11:58:50.941898 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:50.951159 kubelet[2434]: E0515 11:58:50.951140 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:51.051801 kubelet[2434]: E0515 11:58:51.051773 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:51.152477 kubelet[2434]: E0515 11:58:51.152333 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:51.252966 kubelet[2434]: E0515 11:58:51.252847 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:51.353411 kubelet[2434]: E0515 11:58:51.353301 2434 kubelet_node_status.go:453] "Error getting the current node from lister" err="node \"10.200.20.25\" not found" May 15 11:58:51.455308 kubelet[2434]: I0515 11:58:51.454874 2434 kuberuntime_manager.go:1633] "Updating runtime config through cri with podcidr" CIDR="192.168.1.0/24" May 15 11:58:51.455401 containerd[1875]: time="2025-05-15T11:58:51.455197560Z" level=info msg="No cni config template is specified, wait for other system components to drop the config." May 15 11:58:51.455873 kubelet[2434]: I0515 11:58:51.455697 2434 kubelet_network.go:61] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="192.168.1.0/24" May 15 11:58:51.942730 kubelet[2434]: E0515 11:58:51.942611 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:51.942730 kubelet[2434]: I0515 11:58:51.942626 2434 apiserver.go:52] "Watching apiserver" May 15 11:58:51.951882 systemd[1]: Created slice kubepods-besteffort-podc79dff75_8e5d_4f15_8064_3c265bc2f78e.slice - libcontainer container kubepods-besteffort-podc79dff75_8e5d_4f15_8064_3c265bc2f78e.slice. May 15 11:58:51.957429 kubelet[2434]: I0515 11:58:51.957385 2434 desired_state_of_world_populator.go:154] "Finished populating initial desired state of world" May 15 11:58:51.961745 systemd[1]: Created slice kubepods-burstable-pod9a864856_6d0e_47ae_a17f_1c705114a99b.slice - libcontainer container kubepods-burstable-pod9a864856_6d0e_47ae_a17f_1c705114a99b.slice. May 15 11:58:51.967309 kubelet[2434]: I0515 11:58:51.967286 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"run\" (UniqueName: \"kubernetes.io/host-path/9a864856-6d0e-47ae-a17f-1c705114a99b-run\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967413 kubelet[2434]: I0515 11:58:51.967400 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"cni-plugin\" (UniqueName: \"kubernetes.io/host-path/9a864856-6d0e-47ae-a17f-1c705114a99b-cni-plugin\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967478 kubelet[2434]: I0515 11:58:51.967468 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"cni\" (UniqueName: \"kubernetes.io/host-path/9a864856-6d0e-47ae-a17f-1c705114a99b-cni\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967544 kubelet[2434]: I0515 11:58:51.967534 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"xtables-lock\" (UniqueName: \"kubernetes.io/host-path/9a864856-6d0e-47ae-a17f-1c705114a99b-xtables-lock\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967624 kubelet[2434]: I0515 11:58:51.967592 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"xtables-lock\" (UniqueName: \"kubernetes.io/host-path/c79dff75-8e5d-4f15-8064-3c265bc2f78e-xtables-lock\") pod \"kube-proxy-ttp8s\" (UID: \"c79dff75-8e5d-4f15-8064-3c265bc2f78e\") " pod="kube-system/kube-proxy-ttp8s" May 15 11:58:51.967782 kubelet[2434]: I0515 11:58:51.967676 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"lib-modules\" (UniqueName: \"kubernetes.io/host-path/c79dff75-8e5d-4f15-8064-3c265bc2f78e-lib-modules\") pod \"kube-proxy-ttp8s\" (UID: \"c79dff75-8e5d-4f15-8064-3c265bc2f78e\") " pod="kube-system/kube-proxy-ttp8s" May 15 11:58:51.967782 kubelet[2434]: I0515 11:58:51.967691 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-z69xs\" (UniqueName: \"kubernetes.io/projected/c79dff75-8e5d-4f15-8064-3c265bc2f78e-kube-api-access-z69xs\") pod \"kube-proxy-ttp8s\" (UID: \"c79dff75-8e5d-4f15-8064-3c265bc2f78e\") " pod="kube-system/kube-proxy-ttp8s" May 15 11:58:51.967782 kubelet[2434]: I0515 11:58:51.967706 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"flannel-cfg\" (UniqueName: \"kubernetes.io/configmap/9a864856-6d0e-47ae-a17f-1c705114a99b-flannel-cfg\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967782 kubelet[2434]: I0515 11:58:51.967717 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-rjwqg\" (UniqueName: \"kubernetes.io/projected/9a864856-6d0e-47ae-a17f-1c705114a99b-kube-api-access-rjwqg\") pod \"kube-flannel-ds-x5qmc\" (UID: \"9a864856-6d0e-47ae-a17f-1c705114a99b\") " pod="kube-flannel/kube-flannel-ds-x5qmc" May 15 11:58:51.967782 kubelet[2434]: I0515 11:58:51.967727 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-proxy\" (UniqueName: \"kubernetes.io/configmap/c79dff75-8e5d-4f15-8064-3c265bc2f78e-kube-proxy\") pod \"kube-proxy-ttp8s\" (UID: \"c79dff75-8e5d-4f15-8064-3c265bc2f78e\") " pod="kube-system/kube-proxy-ttp8s" May 15 11:58:52.261070 containerd[1875]: time="2025-05-15T11:58:52.260657648Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-proxy-ttp8s,Uid:c79dff75-8e5d-4f15-8064-3c265bc2f78e,Namespace:kube-system,Attempt:0,}" May 15 11:58:52.267637 containerd[1875]: time="2025-05-15T11:58:52.267612768Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-flannel-ds-x5qmc,Uid:9a864856-6d0e-47ae-a17f-1c705114a99b,Namespace:kube-flannel,Attempt:0,}" May 15 11:58:52.942847 kubelet[2434]: E0515 11:58:52.942794 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:53.218960 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount1049270101.mount: Deactivated successfully. May 15 11:58:53.262639 containerd[1875]: time="2025-05-15T11:58:53.262330752Z" level=info msg="ImageCreate event name:\"registry.k8s.io/pause:3.10\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" May 15 11:58:53.271034 containerd[1875]: time="2025-05-15T11:58:53.270990352Z" level=info msg="stop pulling image registry.k8s.io/pause:3.10: active requests=0, bytes read=268703" May 15 11:58:53.275047 containerd[1875]: time="2025-05-15T11:58:53.274649704Z" level=info msg="ImageUpdate event name:\"registry.k8s.io/pause:3.10\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" May 15 11:58:53.277430 containerd[1875]: time="2025-05-15T11:58:53.277408064Z" level=info msg="stop pulling image registry.k8s.io/pause:3.10: active requests=0, bytes read=0" May 15 11:58:53.280175 containerd[1875]: time="2025-05-15T11:58:53.280150512Z" level=info msg="ImageCreate event name:\"sha256:afb61768ce381961ca0beff95337601f29dc70ff3ed14e5e4b3e5699057e6aa8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" May 15 11:58:53.289203 containerd[1875]: time="2025-05-15T11:58:53.289174592Z" level=info msg="ImageCreate event name:\"registry.k8s.io/pause@sha256:ee6521f290b2168b6e0935a181d4cff9be1ac3f505666ef0e3c98fae8199917a\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"} labels:{key:\"io.cri-containerd.pinned\" value:\"pinned\"}" May 15 11:58:53.289650 containerd[1875]: time="2025-05-15T11:58:53.289625288Z" level=info msg="Pulled image \"registry.k8s.io/pause:3.10\" with image id \"sha256:afb61768ce381961ca0beff95337601f29dc70ff3ed14e5e4b3e5699057e6aa8\", repo tag \"registry.k8s.io/pause:3.10\", repo digest \"registry.k8s.io/pause@sha256:ee6521f290b2168b6e0935a181d4cff9be1ac3f505666ef0e3c98fae8199917a\", size \"267933\" in 1.000947264s" May 15 11:58:53.290486 containerd[1875]: time="2025-05-15T11:58:53.290460904Z" level=info msg="Pulled image \"registry.k8s.io/pause:3.10\" with image id \"sha256:afb61768ce381961ca0beff95337601f29dc70ff3ed14e5e4b3e5699057e6aa8\", repo tag \"registry.k8s.io/pause:3.10\", repo digest \"registry.k8s.io/pause@sha256:ee6521f290b2168b6e0935a181d4cff9be1ac3f505666ef0e3c98fae8199917a\", size \"267933\" in 1.007093728s" May 15 11:58:53.370472 containerd[1875]: time="2025-05-15T11:58:53.370432480Z" level=info msg="connecting to shim 2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65" address="unix:///run/containerd/s/9033b60c362ffed493898389fe09fa1fdc69bef883a9246ae6107a6d6f89406d" namespace=k8s.io protocol=ttrpc version=3 May 15 11:58:53.375691 containerd[1875]: time="2025-05-15T11:58:53.375019008Z" level=info msg="connecting to shim 08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02" address="unix:///run/containerd/s/f5ff23da13a66baeb61f2e332dc9b61b5ed57b5b071f1dada57d712a88efdb0d" namespace=k8s.io protocol=ttrpc version=3 May 15 11:58:53.391731 systemd[1]: Started cri-containerd-2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65.scope - libcontainer container 2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65. May 15 11:58:53.394531 systemd[1]: Started cri-containerd-08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02.scope - libcontainer container 08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02. May 15 11:58:53.425465 containerd[1875]: time="2025-05-15T11:58:53.425391272Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-proxy-ttp8s,Uid:c79dff75-8e5d-4f15-8064-3c265bc2f78e,Namespace:kube-system,Attempt:0,} returns sandbox id \"08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02\"" May 15 11:58:53.427229 containerd[1875]: time="2025-05-15T11:58:53.427112256Z" level=info msg="PullImage \"registry.k8s.io/kube-proxy:v1.31.8\"" May 15 11:58:53.429808 containerd[1875]: time="2025-05-15T11:58:53.429762224Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:kube-flannel-ds-x5qmc,Uid:9a864856-6d0e-47ae-a17f-1c705114a99b,Namespace:kube-flannel,Attempt:0,} returns sandbox id \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\"" May 15 11:58:53.943007 kubelet[2434]: E0515 11:58:53.942942 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:54.423294 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount3793292811.mount: Deactivated successfully. May 15 11:58:54.715494 containerd[1875]: time="2025-05-15T11:58:54.714924168Z" level=info msg="ImageCreate event name:\"registry.k8s.io/kube-proxy:v1.31.8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:54.718453 containerd[1875]: time="2025-05-15T11:58:54.718428344Z" level=info msg="stop pulling image registry.k8s.io/kube-proxy:v1.31.8: active requests=0, bytes read=26871917" May 15 11:58:54.725130 containerd[1875]: time="2025-05-15T11:58:54.725098584Z" level=info msg="ImageCreate event name:\"sha256:c5361ece77e80334cd5fb082c0b678cb3244f5834ecacea1719ae6b38b465581\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:54.735504 containerd[1875]: time="2025-05-15T11:58:54.735481416Z" level=info msg="ImageCreate event name:\"registry.k8s.io/kube-proxy@sha256:dd0c9a37670f209947b1ed880f06a2e93e1d41da78c037f52f94b13858769838\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:54.735753 containerd[1875]: time="2025-05-15T11:58:54.735730392Z" level=info msg="Pulled image \"registry.k8s.io/kube-proxy:v1.31.8\" with image id \"sha256:c5361ece77e80334cd5fb082c0b678cb3244f5834ecacea1719ae6b38b465581\", repo tag \"registry.k8s.io/kube-proxy:v1.31.8\", repo digest \"registry.k8s.io/kube-proxy@sha256:dd0c9a37670f209947b1ed880f06a2e93e1d41da78c037f52f94b13858769838\", size \"26870936\" in 1.30854404s" May 15 11:58:54.736063 containerd[1875]: time="2025-05-15T11:58:54.735756624Z" level=info msg="PullImage \"registry.k8s.io/kube-proxy:v1.31.8\" returns image reference \"sha256:c5361ece77e80334cd5fb082c0b678cb3244f5834ecacea1719ae6b38b465581\"" May 15 11:58:54.737340 containerd[1875]: time="2025-05-15T11:58:54.737306496Z" level=info msg="PullImage \"docker.io/flannel/flannel-cni-plugin:v1.1.2\"" May 15 11:58:54.738305 containerd[1875]: time="2025-05-15T11:58:54.738280216Z" level=info msg="CreateContainer within sandbox \"08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02\" for container &ContainerMetadata{Name:kube-proxy,Attempt:0,}" May 15 11:58:54.777617 containerd[1875]: time="2025-05-15T11:58:54.777162864Z" level=info msg="Container f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a: CDI devices from CRI Config.CDIDevices: []" May 15 11:58:54.778826 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount2795338015.mount: Deactivated successfully. May 15 11:58:54.798657 containerd[1875]: time="2025-05-15T11:58:54.798625568Z" level=info msg="CreateContainer within sandbox \"08d3d3e62741a1ae53f820d5e942731fdb169ca216ed15b89e2783b4fa163b02\" for &ContainerMetadata{Name:kube-proxy,Attempt:0,} returns container id \"f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a\"" May 15 11:58:54.799450 containerd[1875]: time="2025-05-15T11:58:54.799425696Z" level=info msg="StartContainer for \"f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a\"" May 15 11:58:54.800369 containerd[1875]: time="2025-05-15T11:58:54.800343608Z" level=info msg="connecting to shim f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a" address="unix:///run/containerd/s/f5ff23da13a66baeb61f2e332dc9b61b5ed57b5b071f1dada57d712a88efdb0d" protocol=ttrpc version=3 May 15 11:58:54.815706 systemd[1]: Started cri-containerd-f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a.scope - libcontainer container f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a. May 15 11:58:54.841451 containerd[1875]: time="2025-05-15T11:58:54.841367056Z" level=info msg="StartContainer for \"f8034a2d799d3278e450d06e7c8b3102e2c4b414ffdd34cd2bb6911d52f5413a\" returns successfully" May 15 11:58:54.943121 kubelet[2434]: E0515 11:58:54.943074 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:55.944160 kubelet[2434]: E0515 11:58:55.944131 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:56.701654 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount4057248127.mount: Deactivated successfully. May 15 11:58:56.789224 containerd[1875]: time="2025-05-15T11:58:56.789173544Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel-cni-plugin:v1.1.2\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:56.798682 containerd[1875]: time="2025-05-15T11:58:56.798651776Z" level=info msg="stop pulling image docker.io/flannel/flannel-cni-plugin:v1.1.2: active requests=0, bytes read=3673532" May 15 11:58:56.801807 containerd[1875]: time="2025-05-15T11:58:56.801780472Z" level=info msg="ImageCreate event name:\"sha256:b45062ceea496fc421523388cb91166abc7715a15c2e2cbab4e6f8c9d5dc0ab8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:56.811052 containerd[1875]: time="2025-05-15T11:58:56.810947784Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel-cni-plugin@sha256:bf4b62b131666d040f35a327d906ee5a3418280b68a88d9b9c7e828057210443\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:58:56.811354 containerd[1875]: time="2025-05-15T11:58:56.811218896Z" 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 2.073550392s" May 15 11:58:56.811354 containerd[1875]: time="2025-05-15T11:58:56.811244136Z" level=info msg="PullImage \"docker.io/flannel/flannel-cni-plugin:v1.1.2\" returns image reference \"sha256:b45062ceea496fc421523388cb91166abc7715a15c2e2cbab4e6f8c9d5dc0ab8\"" May 15 11:58:56.813049 containerd[1875]: time="2025-05-15T11:58:56.813027856Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for container &ContainerMetadata{Name:install-cni-plugin,Attempt:0,}" May 15 11:58:56.840260 containerd[1875]: time="2025-05-15T11:58:56.840230528Z" level=info msg="Container b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a: CDI devices from CRI Config.CDIDevices: []" May 15 11:58:56.867466 containerd[1875]: time="2025-05-15T11:58:56.867430488Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for &ContainerMetadata{Name:install-cni-plugin,Attempt:0,} returns container id \"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\"" May 15 11:58:56.867991 containerd[1875]: time="2025-05-15T11:58:56.867966952Z" level=info msg="StartContainer for \"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\"" May 15 11:58:56.868547 containerd[1875]: time="2025-05-15T11:58:56.868504200Z" level=info msg="connecting to shim b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a" address="unix:///run/containerd/s/9033b60c362ffed493898389fe09fa1fdc69bef883a9246ae6107a6d6f89406d" protocol=ttrpc version=3 May 15 11:58:56.881725 systemd[1]: Started cri-containerd-b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a.scope - libcontainer container b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a. May 15 11:58:56.901060 systemd[1]: cri-containerd-b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a.scope: Deactivated successfully. May 15 11:58:56.904664 containerd[1875]: time="2025-05-15T11:58:56.903257792Z" level=info msg="TaskExit event in podsandbox handler container_id:\"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\" id:\"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\" pid:2765 exited_at:{seconds:1747310336 nanos:902624392}" May 15 11:58:56.906681 containerd[1875]: time="2025-05-15T11:58:56.906650976Z" level=info msg="received exit event container_id:\"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\" id:\"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\" pid:2765 exited_at:{seconds:1747310336 nanos:902624392}" May 15 11:58:56.907490 containerd[1875]: time="2025-05-15T11:58:56.907317656Z" level=info msg="StartContainer for \"b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a\" returns successfully" May 15 11:58:56.945631 kubelet[2434]: E0515 11:58:56.944547 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:57.072964 kubelet[2434]: I0515 11:58:57.072731 2434 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-system/kube-proxy-ttp8s" podStartSLOduration=5.762838128 podStartE2EDuration="7.072717216s" podCreationTimestamp="2025-05-15 11:58:50 +0000 UTC" firstStartedPulling="2025-05-15 11:58:53.426765472 +0000 UTC m=+3.996553753" lastFinishedPulling="2025-05-15 11:58:54.73664456 +0000 UTC m=+5.306432841" observedRunningTime="2025-05-15 11:58:55.052827 +0000 UTC m=+5.622615281" watchObservedRunningTime="2025-05-15 11:58:57.072717216 +0000 UTC m=+7.642505497" May 15 11:58:57.653615 systemd[1]: run-containerd-io.containerd.runtime.v2.task-k8s.io-b408d0cfea16b2354206f3111a0112fa17b99fb75fad84fc6d63b679e243d85a-rootfs.mount: Deactivated successfully. May 15 11:58:57.944892 kubelet[2434]: E0515 11:58:57.944760 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:58.050311 containerd[1875]: time="2025-05-15T11:58:58.050271384Z" level=info msg="PullImage \"docker.io/flannel/flannel:v0.22.0\"" May 15 11:58:58.945020 kubelet[2434]: E0515 11:58:58.944973 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:58:59.894681 chronyd[1849]: Selected source PHC0 May 15 11:58:59.925951 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount1264739810.mount: Deactivated successfully. May 15 11:58:59.945245 kubelet[2434]: E0515 11:58:59.945206 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:00.871670 containerd[1875]: time="2025-05-15T11:59:00.871621071Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel:v0.22.0\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:00.880061 containerd[1875]: time="2025-05-15T11:59:00.880001853Z" level=info msg="stop pulling image docker.io/flannel/flannel:v0.22.0: active requests=0, bytes read=26874261" May 15 11:59:00.897318 containerd[1875]: time="2025-05-15T11:59:00.897259119Z" level=info msg="ImageCreate event name:\"sha256:b3d1319ea6da12d4a1dd21a923f6a71f942a7b6e2c4763b8a3cca0725fb8aadf\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:00.913491 containerd[1875]: time="2025-05-15T11:59:00.913433256Z" level=info msg="ImageCreate event name:\"docker.io/flannel/flannel@sha256:5f83f1243057458e27249157394e3859cf31cc075354af150d497f2ebc8b54db\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:00.914166 containerd[1875]: time="2025-05-15T11:59:00.914063032Z" 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 2.863369048s" May 15 11:59:00.914166 containerd[1875]: time="2025-05-15T11:59:00.914090648Z" level=info msg="PullImage \"docker.io/flannel/flannel:v0.22.0\" returns image reference \"sha256:b3d1319ea6da12d4a1dd21a923f6a71f942a7b6e2c4763b8a3cca0725fb8aadf\"" May 15 11:59:00.916001 containerd[1875]: time="2025-05-15T11:59:00.915933079Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for container &ContainerMetadata{Name:install-cni,Attempt:0,}" May 15 11:59:00.942630 containerd[1875]: time="2025-05-15T11:59:00.942585811Z" level=info msg="Container e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986: CDI devices from CRI Config.CDIDevices: []" May 15 11:59:00.945772 kubelet[2434]: E0515 11:59:00.945747 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:00.962438 containerd[1875]: time="2025-05-15T11:59:00.962403161Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for &ContainerMetadata{Name:install-cni,Attempt:0,} returns container id \"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\"" May 15 11:59:00.962971 containerd[1875]: time="2025-05-15T11:59:00.962949537Z" level=info msg="StartContainer for \"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\"" May 15 11:59:00.963570 containerd[1875]: time="2025-05-15T11:59:00.963549753Z" level=info msg="connecting to shim e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986" address="unix:///run/containerd/s/9033b60c362ffed493898389fe09fa1fdc69bef883a9246ae6107a6d6f89406d" protocol=ttrpc version=3 May 15 11:59:00.982718 systemd[1]: Started cri-containerd-e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986.scope - libcontainer container e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986. May 15 11:59:00.999835 systemd[1]: cri-containerd-e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986.scope: Deactivated successfully. May 15 11:59:01.001213 containerd[1875]: time="2025-05-15T11:59:01.001179192Z" level=info msg="TaskExit event in podsandbox handler container_id:\"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\" id:\"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\" pid:2840 exited_at:{seconds:1747310341 nanos:588320}" May 15 11:59:01.005741 containerd[1875]: time="2025-05-15T11:59:01.005640406Z" level=info msg="received exit event container_id:\"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\" id:\"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\" pid:2840 exited_at:{seconds:1747310341 nanos:588320}" May 15 11:59:01.007012 containerd[1875]: time="2025-05-15T11:59:01.006865573Z" level=info msg="StartContainer for \"e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986\" returns successfully" May 15 11:59:01.018755 systemd[1]: run-containerd-io.containerd.runtime.v2.task-k8s.io-e179898fc2ad4f2d0b92bb20aee5d8cd118a1ba7a00fcac60c5374c20964b986-rootfs.mount: Deactivated successfully. May 15 11:59:01.024412 kubelet[2434]: I0515 11:59:01.024362 2434 kubelet_node_status.go:488] "Fast updating node status as it just became ready" May 15 11:59:01.947135 kubelet[2434]: E0515 11:59:01.947083 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:02.059609 containerd[1875]: time="2025-05-15T11:59:02.059529349Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for container &ContainerMetadata{Name:kube-flannel,Attempt:0,}" May 15 11:59:02.086363 containerd[1875]: time="2025-05-15T11:59:02.085129125Z" level=info msg="Container 7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a: CDI devices from CRI Config.CDIDevices: []" May 15 11:59:02.087425 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount2005776884.mount: Deactivated successfully. May 15 11:59:02.112741 containerd[1875]: time="2025-05-15T11:59:02.112622269Z" level=info msg="CreateContainer within sandbox \"2f4139838972f596657d372f075a523d864a2450232a720e5bf038c1e0b5fd65\" for &ContainerMetadata{Name:kube-flannel,Attempt:0,} returns container id \"7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a\"" May 15 11:59:02.112741 containerd[1875]: time="2025-05-15T11:59:02.113175389Z" level=info msg="StartContainer for \"7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a\"" May 15 11:59:02.113992 containerd[1875]: time="2025-05-15T11:59:02.113958453Z" level=info msg="connecting to shim 7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a" address="unix:///run/containerd/s/9033b60c362ffed493898389fe09fa1fdc69bef883a9246ae6107a6d6f89406d" protocol=ttrpc version=3 May 15 11:59:02.131723 systemd[1]: Started cri-containerd-7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a.scope - libcontainer container 7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a. May 15 11:59:02.154416 containerd[1875]: time="2025-05-15T11:59:02.154374133Z" level=info msg="StartContainer for \"7cd34363053c0a0899106dd5fdba9c4491d52ca4368c4625dbdeafd1f0d2260a\" returns successfully" May 15 11:59:02.948239 kubelet[2434]: E0515 11:59:02.948195 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:03.073404 kubelet[2434]: I0515 11:59:03.073357 2434 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="kube-flannel/kube-flannel-ds-x5qmc" podStartSLOduration=5.588962501 podStartE2EDuration="13.073343453s" podCreationTimestamp="2025-05-15 11:58:50 +0000 UTC" firstStartedPulling="2025-05-15 11:58:53.430438864 +0000 UTC m=+4.000227145" lastFinishedPulling="2025-05-15 11:59:00.914819816 +0000 UTC m=+11.484608097" observedRunningTime="2025-05-15 11:59:03.073285381 +0000 UTC m=+13.643073686" watchObservedRunningTime="2025-05-15 11:59:03.073343453 +0000 UTC m=+13.643131734" May 15 11:59:03.291355 systemd-networkd[1482]: flannel.1: Link UP May 15 11:59:03.291362 systemd-networkd[1482]: flannel.1: Gained carrier May 15 11:59:03.949034 kubelet[2434]: E0515 11:59:03.948978 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:04.271048 systemd[1]: Created slice kubepods-besteffort-pod7aff717d_f511_4368_8c8e_a86f53ff3326.slice - libcontainer container kubepods-besteffort-pod7aff717d_f511_4368_8c8e_a86f53ff3326.slice. May 15 11:59:04.336624 kubelet[2434]: I0515 11:59:04.336543 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-r5t75\" (UniqueName: \"kubernetes.io/projected/7aff717d-f511-4368-8c8e-a86f53ff3326-kube-api-access-r5t75\") pod \"nginx-deployment-8587fbcb89-l4csl\" (UID: \"7aff717d-f511-4368-8c8e-a86f53ff3326\") " pod="default/nginx-deployment-8587fbcb89-l4csl" May 15 11:59:04.436809 systemd-networkd[1482]: flannel.1: Gained IPv6LL May 15 11:59:04.573667 containerd[1875]: time="2025-05-15T11:59:04.573531413Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nginx-deployment-8587fbcb89-l4csl,Uid:7aff717d-f511-4368-8c8e-a86f53ff3326,Namespace:default,Attempt:0,}" May 15 11:59:04.592360 systemd-networkd[1482]: cni0: Link UP May 15 11:59:04.625612 systemd-networkd[1482]: veth1589e3ef: Link UP May 15 11:59:04.632861 kernel: cni0: port 1(veth1589e3ef) entered blocking state May 15 11:59:04.632939 kernel: cni0: port 1(veth1589e3ef) entered disabled state May 15 11:59:04.637406 kernel: veth1589e3ef: entered allmulticast mode May 15 11:59:04.641019 kernel: veth1589e3ef: entered promiscuous mode May 15 11:59:04.649840 kernel: cni0: port 1(veth1589e3ef) entered blocking state May 15 11:59:04.650040 kernel: cni0: port 1(veth1589e3ef) entered forwarding state May 15 11:59:04.650136 systemd-networkd[1482]: veth1589e3ef: Gained carrier May 15 11:59:04.650352 systemd-networkd[1482]: cni0: Gained carrier May 15 11:59:04.652530 containerd[1875]: 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)(0x40000928e8), "name":"cbr0", "type":"bridge"} May 15 11:59:04.652530 containerd[1875]: delegateAdd: netconf sent to delegate plugin: May 15 11:59:04.712351 containerd[1875]: {"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="2025-05-15T11:59:04.712305413Z" level=info msg="connecting to shim 0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0" address="unix:///run/containerd/s/52b49e8a7975f3d856dfbfdb1c50ab2c37bfe87e461959b39dfcadaf150a3212" namespace=k8s.io protocol=ttrpc version=3 May 15 11:59:04.735735 systemd[1]: Started cri-containerd-0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0.scope - libcontainer container 0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0. May 15 11:59:04.763254 containerd[1875]: time="2025-05-15T11:59:04.763221149Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nginx-deployment-8587fbcb89-l4csl,Uid:7aff717d-f511-4368-8c8e-a86f53ff3326,Namespace:default,Attempt:0,} returns sandbox id \"0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0\"" May 15 11:59:04.764900 containerd[1875]: time="2025-05-15T11:59:04.764876933Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\"" May 15 11:59:04.950142 kubelet[2434]: E0515 11:59:04.950086 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:05.844777 systemd-networkd[1482]: cni0: Gained IPv6LL May 15 11:59:05.950478 kubelet[2434]: E0515 11:59:05.950426 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:06.164830 systemd-networkd[1482]: veth1589e3ef: Gained IPv6LL May 15 11:59:06.951529 kubelet[2434]: E0515 11:59:06.951460 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:07.112739 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount2218270350.mount: Deactivated successfully. May 15 11:59:07.952432 kubelet[2434]: E0515 11:59:07.952387 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:08.639385 containerd[1875]: time="2025-05-15T11:59:08.638779633Z" level=info msg="ImageCreate event name:\"ghcr.io/flatcar/nginx:latest\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:08.641285 containerd[1875]: time="2025-05-15T11:59:08.641262146Z" level=info msg="stop pulling image ghcr.io/flatcar/nginx:latest: active requests=0, bytes read=69948859" May 15 11:59:08.645558 containerd[1875]: time="2025-05-15T11:59:08.645534049Z" level=info msg="ImageCreate event name:\"sha256:e8b1cb61bd96acc3ff3c695318c9cc691213d532eee3731d038af92816fcb5f4\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:08.650590 containerd[1875]: time="2025-05-15T11:59:08.650567940Z" level=info msg="ImageCreate event name:\"ghcr.io/flatcar/nginx@sha256:beabce8f1782671ba500ddff99dd260fbf9c5ec85fb9c3162e35a3c40bafd023\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:08.651097 containerd[1875]: time="2025-05-15T11:59:08.651072109Z" level=info msg="Pulled image \"ghcr.io/flatcar/nginx:latest\" with image id \"sha256:e8b1cb61bd96acc3ff3c695318c9cc691213d532eee3731d038af92816fcb5f4\", repo tag \"ghcr.io/flatcar/nginx:latest\", repo digest \"ghcr.io/flatcar/nginx@sha256:beabce8f1782671ba500ddff99dd260fbf9c5ec85fb9c3162e35a3c40bafd023\", size \"69948737\" in 3.88616863s" May 15 11:59:08.651257 containerd[1875]: time="2025-05-15T11:59:08.651172929Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\" returns image reference \"sha256:e8b1cb61bd96acc3ff3c695318c9cc691213d532eee3731d038af92816fcb5f4\"" May 15 11:59:08.652710 containerd[1875]: time="2025-05-15T11:59:08.652680715Z" level=info msg="CreateContainer within sandbox \"0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0\" for container &ContainerMetadata{Name:nginx,Attempt:0,}" May 15 11:59:08.768609 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount765607242.mount: Deactivated successfully. May 15 11:59:08.770589 containerd[1875]: time="2025-05-15T11:59:08.770187130Z" level=info msg="Container ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c: CDI devices from CRI Config.CDIDevices: []" May 15 11:59:08.793060 containerd[1875]: time="2025-05-15T11:59:08.793027678Z" level=info msg="CreateContainer within sandbox \"0c924a504fcbfdaf09688cddd77b6b953e3e40b6e79d54d2425ce645fbfd4af0\" for &ContainerMetadata{Name:nginx,Attempt:0,} returns container id \"ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c\"" May 15 11:59:08.793770 containerd[1875]: time="2025-05-15T11:59:08.793587619Z" level=info msg="StartContainer for \"ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c\"" May 15 11:59:08.794197 containerd[1875]: time="2025-05-15T11:59:08.794173737Z" level=info msg="connecting to shim ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c" address="unix:///run/containerd/s/52b49e8a7975f3d856dfbfdb1c50ab2c37bfe87e461959b39dfcadaf150a3212" protocol=ttrpc version=3 May 15 11:59:08.812847 systemd[1]: Started cri-containerd-ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c.scope - libcontainer container ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c. May 15 11:59:08.838626 containerd[1875]: time="2025-05-15T11:59:08.838580288Z" level=info msg="StartContainer for \"ec020a9fa8ceb1daa3b12598fd8f85ae344c3ab63dea0aab9ca715ad2a3d719c\" returns successfully" May 15 11:59:08.953707 kubelet[2434]: E0515 11:59:08.953530 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:09.941649 kubelet[2434]: E0515 11:59:09.941608 2434 file.go:104] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:09.954021 kubelet[2434]: E0515 11:59:09.953993 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:10.954930 kubelet[2434]: E0515 11:59:10.954892 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:11.955330 kubelet[2434]: E0515 11:59:11.955193 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:12.956086 kubelet[2434]: E0515 11:59:12.956041 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:13.930626 kubelet[2434]: I0515 11:59:13.930156 2434 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="default/nginx-deployment-8587fbcb89-l4csl" podStartSLOduration=6.042798752 podStartE2EDuration="9.930138234s" podCreationTimestamp="2025-05-15 11:59:04 +0000 UTC" firstStartedPulling="2025-05-15 11:59:04.764465285 +0000 UTC m=+15.334253566" lastFinishedPulling="2025-05-15 11:59:08.651804767 +0000 UTC m=+19.221593048" observedRunningTime="2025-05-15 11:59:09.08256211 +0000 UTC m=+19.652350391" watchObservedRunningTime="2025-05-15 11:59:13.930138234 +0000 UTC m=+24.499926515" May 15 11:59:13.935534 systemd[1]: Created slice kubepods-besteffort-pod78b09c50_d44e_4890_bea6_999ad88f752d.slice - libcontainer container kubepods-besteffort-pod78b09c50_d44e_4890_bea6_999ad88f752d.slice. May 15 11:59:13.957078 kubelet[2434]: E0515 11:59:13.957033 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:13.986473 kubelet[2434]: I0515 11:59:13.986437 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"data\" (UniqueName: \"kubernetes.io/empty-dir/78b09c50-d44e-4890-bea6-999ad88f752d-data\") pod \"nfs-server-provisioner-0\" (UID: \"78b09c50-d44e-4890-bea6-999ad88f752d\") " pod="default/nfs-server-provisioner-0" May 15 11:59:13.986641 kubelet[2434]: I0515 11:59:13.986590 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-jnbfx\" (UniqueName: \"kubernetes.io/projected/78b09c50-d44e-4890-bea6-999ad88f752d-kube-api-access-jnbfx\") pod \"nfs-server-provisioner-0\" (UID: \"78b09c50-d44e-4890-bea6-999ad88f752d\") " pod="default/nfs-server-provisioner-0" May 15 11:59:14.238810 containerd[1875]: time="2025-05-15T11:59:14.238638690Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nfs-server-provisioner-0,Uid:78b09c50-d44e-4890-bea6-999ad88f752d,Namespace:default,Attempt:0,}" May 15 11:59:14.258154 systemd-networkd[1482]: veth6ba160b6: Link UP May 15 11:59:14.266154 kernel: cni0: port 2(veth6ba160b6) entered blocking state May 15 11:59:14.266298 kernel: cni0: port 2(veth6ba160b6) entered disabled state May 15 11:59:14.266329 kernel: veth6ba160b6: entered allmulticast mode May 15 11:59:14.272024 kernel: veth6ba160b6: entered promiscuous mode May 15 11:59:14.281366 kernel: cni0: port 2(veth6ba160b6) entered blocking state May 15 11:59:14.281836 kernel: cni0: port 2(veth6ba160b6) entered forwarding state May 15 11:59:14.281654 systemd-networkd[1482]: veth6ba160b6: Gained carrier May 15 11:59:14.282786 containerd[1875]: 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)(0x4000018928), "name":"cbr0", "type":"bridge"} May 15 11:59:14.282786 containerd[1875]: delegateAdd: netconf sent to delegate plugin: May 15 11:59:14.409310 containerd[1875]: {"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="2025-05-15T11:59:14.409218894Z" level=info msg="connecting to shim 9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747" address="unix:///run/containerd/s/7704d196b58dd6786495482a969dce75e593e38ecee16c4e3b7c79769d98f221" namespace=k8s.io protocol=ttrpc version=3 May 15 11:59:14.429772 systemd[1]: Started cri-containerd-9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747.scope - libcontainer container 9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747. May 15 11:59:14.461850 containerd[1875]: time="2025-05-15T11:59:14.461814824Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:nfs-server-provisioner-0,Uid:78b09c50-d44e-4890-bea6-999ad88f752d,Namespace:default,Attempt:0,} returns sandbox id \"9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747\"" May 15 11:59:14.463116 containerd[1875]: time="2025-05-15T11:59:14.463086864Z" level=info msg="PullImage \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\"" May 15 11:59:14.957428 kubelet[2434]: E0515 11:59:14.957378 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:15.381732 systemd-networkd[1482]: veth6ba160b6: Gained IPv6LL May 15 11:59:15.958465 kubelet[2434]: E0515 11:59:15.958412 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:16.704290 systemd[1]: var-lib-containerd-tmpmounts-containerd\x2dmount1277976940.mount: Deactivated successfully. May 15 11:59:16.959452 kubelet[2434]: E0515 11:59:16.959214 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:17.959425 kubelet[2434]: E0515 11:59:17.959373 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:18.578049 containerd[1875]: time="2025-05-15T11:59:18.577991092Z" level=info msg="ImageCreate event name:\"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:18.581981 containerd[1875]: time="2025-05-15T11:59:18.581818782Z" level=info msg="stop pulling image registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8: active requests=0, bytes read=87373623" May 15 11:59:18.585846 containerd[1875]: time="2025-05-15T11:59:18.585819269Z" level=info msg="ImageCreate event name:\"sha256:5a42a519e0a8cf95c3c5f18f767c58c8c8b072aaea0a26e5e47a6f206c7df685\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:18.590240 containerd[1875]: time="2025-05-15T11:59:18.590176471Z" level=info msg="ImageCreate event name:\"registry.k8s.io/sig-storage/nfs-provisioner@sha256:c825f3d5e28bde099bd7a3daace28772d412c9157ad47fa752a9ad0baafc118d\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:18.590991 containerd[1875]: time="2025-05-15T11:59:18.590700311Z" 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 4.12758455s" May 15 11:59:18.590991 containerd[1875]: time="2025-05-15T11:59:18.590733976Z" level=info msg="PullImage \"registry.k8s.io/sig-storage/nfs-provisioner:v4.0.8\" returns image reference \"sha256:5a42a519e0a8cf95c3c5f18f767c58c8c8b072aaea0a26e5e47a6f206c7df685\"" May 15 11:59:18.592781 containerd[1875]: time="2025-05-15T11:59:18.592751752Z" level=info msg="CreateContainer within sandbox \"9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747\" for container &ContainerMetadata{Name:nfs-server-provisioner,Attempt:0,}" May 15 11:59:18.619736 containerd[1875]: time="2025-05-15T11:59:18.619696919Z" level=info msg="Container d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319: CDI devices from CRI Config.CDIDevices: []" May 15 11:59:18.646294 containerd[1875]: time="2025-05-15T11:59:18.646208192Z" level=info msg="CreateContainer within sandbox \"9b81d0aac64875f7217a6b83fa1c730d638a98e00e3701b86611b3fad2480747\" for &ContainerMetadata{Name:nfs-server-provisioner,Attempt:0,} returns container id \"d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319\"" May 15 11:59:18.646949 containerd[1875]: time="2025-05-15T11:59:18.646921895Z" level=info msg="StartContainer for \"d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319\"" May 15 11:59:18.647735 containerd[1875]: time="2025-05-15T11:59:18.647713184Z" level=info msg="connecting to shim d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319" address="unix:///run/containerd/s/7704d196b58dd6786495482a969dce75e593e38ecee16c4e3b7c79769d98f221" protocol=ttrpc version=3 May 15 11:59:18.665728 systemd[1]: Started cri-containerd-d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319.scope - libcontainer container d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319. May 15 11:59:18.688889 containerd[1875]: time="2025-05-15T11:59:18.688835977Z" level=info msg="StartContainer for \"d2ae8195965a26f3712e03f9793e83b5b80ed8199b99aeac8619b14ec9a11319\" returns successfully" May 15 11:59:18.959632 kubelet[2434]: E0515 11:59:18.959581 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:19.101593 kubelet[2434]: I0515 11:59:19.101537 2434 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="default/nfs-server-provisioner-0" podStartSLOduration=1.972814015 podStartE2EDuration="6.101523571s" podCreationTimestamp="2025-05-15 11:59:13 +0000 UTC" firstStartedPulling="2025-05-15 11:59:14.4627561 +0000 UTC m=+25.032544381" lastFinishedPulling="2025-05-15 11:59:18.591465656 +0000 UTC m=+29.161253937" observedRunningTime="2025-05-15 11:59:19.101445201 +0000 UTC m=+29.671233482" watchObservedRunningTime="2025-05-15 11:59:19.101523571 +0000 UTC m=+29.671311852" May 15 11:59:19.150847 kernel: hv_balloon: Max. dynamic memory size: 4096 MB May 15 11:59:19.960299 kubelet[2434]: E0515 11:59:19.960263 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:20.960761 kubelet[2434]: E0515 11:59:20.960717 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:21.961545 kubelet[2434]: E0515 11:59:21.961498 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:22.145163 update_engine[1856]: I20250515 11:59:22.145093 1856 update_attempter.cc:509] Updating boot flags... May 15 11:59:22.961771 kubelet[2434]: E0515 11:59:22.961722 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:23.962076 kubelet[2434]: E0515 11:59:23.962028 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:24.962321 kubelet[2434]: E0515 11:59:24.962271 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:25.963091 kubelet[2434]: E0515 11:59:25.963049 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:26.963380 kubelet[2434]: E0515 11:59:26.963332 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:27.963811 kubelet[2434]: E0515 11:59:27.963688 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:28.541229 systemd[1]: Created slice kubepods-besteffort-pod8c995837_8ed4_4d59_9762_ccb902aae769.slice - libcontainer container kubepods-besteffort-pod8c995837_8ed4_4d59_9762_ccb902aae769.slice. May 15 11:59:28.559707 kubelet[2434]: I0515 11:59:28.559680 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"kube-api-access-njh6m\" (UniqueName: \"kubernetes.io/projected/8c995837-8ed4-4d59-9762-ccb902aae769-kube-api-access-njh6m\") pod \"test-pod-1\" (UID: \"8c995837-8ed4-4d59-9762-ccb902aae769\") " pod="default/test-pod-1" May 15 11:59:28.559707 kubelet[2434]: I0515 11:59:28.559709 2434 reconciler_common.go:245] "operationExecutor.VerifyControllerAttachedVolume started for volume \"pvc-42c93698-aa8e-4b2b-b9b3-ab675a02b1f1\" (UniqueName: \"kubernetes.io/nfs/8c995837-8ed4-4d59-9762-ccb902aae769-pvc-42c93698-aa8e-4b2b-b9b3-ab675a02b1f1\") pod \"test-pod-1\" (UID: \"8c995837-8ed4-4d59-9762-ccb902aae769\") " pod="default/test-pod-1" May 15 11:59:28.873627 kernel: netfs: FS-Cache loaded May 15 11:59:28.930938 kernel: RPC: Registered named UNIX socket transport module. May 15 11:59:28.931058 kernel: RPC: Registered udp transport module. May 15 11:59:28.931073 kernel: RPC: Registered tcp transport module. May 15 11:59:28.936338 kernel: RPC: Registered tcp-with-tls transport module. May 15 11:59:28.936374 kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. May 15 11:59:28.964143 kubelet[2434]: E0515 11:59:28.964099 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:29.120090 kernel: NFS: Registering the id_resolver key type May 15 11:59:29.120211 kernel: Key type id_resolver registered May 15 11:59:29.120228 kernel: Key type id_legacy registered May 15 11:59:29.232977 nfsidmap[3555]: nss_getpwnam: name 'root@nfs-server-provisioner.default.svc.cluster.local' does not map into domain '0.0-a-072134ebcf' May 15 11:59:29.271486 nfsidmap[3556]: nss_name_to_gid: name 'root@nfs-server-provisioner.default.svc.cluster.local' does not map into domain '0.0-a-072134ebcf' May 15 11:59:29.280002 nfsrahead[3559]: setting /var/lib/kubelet/pods/8c995837-8ed4-4d59-9762-ccb902aae769/volumes/kubernetes.io~nfs/pvc-42c93698-aa8e-4b2b-b9b3-ab675a02b1f1 readahead to 128 May 15 11:59:29.444395 containerd[1875]: time="2025-05-15T11:59:29.444362595Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:test-pod-1,Uid:8c995837-8ed4-4d59-9762-ccb902aae769,Namespace:default,Attempt:0,}" May 15 11:59:29.473748 systemd-networkd[1482]: vethf1316db0: Link UP May 15 11:59:29.481941 kernel: cni0: port 3(vethf1316db0) entered blocking state May 15 11:59:29.482011 kernel: cni0: port 3(vethf1316db0) entered disabled state May 15 11:59:29.482026 kernel: vethf1316db0: entered allmulticast mode May 15 11:59:29.487352 kernel: vethf1316db0: entered promiscuous mode May 15 11:59:29.496743 kernel: cni0: port 3(vethf1316db0) entered blocking state May 15 11:59:29.496812 kernel: cni0: port 3(vethf1316db0) entered forwarding state May 15 11:59:29.496825 systemd-networkd[1482]: vethf1316db0: Gained carrier May 15 11:59:29.498450 containerd[1875]: 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)(0x40000948e8), "name":"cbr0", "type":"bridge"} May 15 11:59:29.498450 containerd[1875]: delegateAdd: netconf sent to delegate plugin: May 15 11:59:29.549257 containerd[1875]: {"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="2025-05-15T11:59:29.549184590Z" level=info msg="connecting to shim 7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca" address="unix:///run/containerd/s/b741dd1628e15f208a759460bf53feee03aea5fe677e782c54a70ed7d3ee5d61" namespace=k8s.io protocol=ttrpc version=3 May 15 11:59:29.565730 systemd[1]: Started cri-containerd-7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca.scope - libcontainer container 7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca. May 15 11:59:29.595914 containerd[1875]: time="2025-05-15T11:59:29.595799754Z" level=info msg="RunPodSandbox for &PodSandboxMetadata{Name:test-pod-1,Uid:8c995837-8ed4-4d59-9762-ccb902aae769,Namespace:default,Attempt:0,} returns sandbox id \"7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca\"" May 15 11:59:29.598302 containerd[1875]: time="2025-05-15T11:59:29.598262521Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\"" May 15 11:59:29.941739 kubelet[2434]: E0515 11:59:29.941694 2434 file.go:104] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:29.964973 kubelet[2434]: E0515 11:59:29.964944 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:30.332519 containerd[1875]: time="2025-05-15T11:59:30.332388311Z" level=info msg="ImageUpdate event name:\"ghcr.io/flatcar/nginx:latest\" labels:{key:\"io.cri-containerd.image\" value:\"managed\"}" May 15 11:59:30.337681 containerd[1875]: time="2025-05-15T11:59:30.337633317Z" level=info msg="stop pulling image ghcr.io/flatcar/nginx:latest: active requests=0, bytes read=61" May 15 11:59:30.339251 containerd[1875]: time="2025-05-15T11:59:30.339217433Z" level=info msg="Pulled image \"ghcr.io/flatcar/nginx:latest\" with image id \"sha256:e8b1cb61bd96acc3ff3c695318c9cc691213d532eee3731d038af92816fcb5f4\", repo tag \"ghcr.io/flatcar/nginx:latest\", repo digest \"ghcr.io/flatcar/nginx@sha256:beabce8f1782671ba500ddff99dd260fbf9c5ec85fb9c3162e35a3c40bafd023\", size \"69948737\" in 740.913767ms" May 15 11:59:30.339251 containerd[1875]: time="2025-05-15T11:59:30.339250530Z" level=info msg="PullImage \"ghcr.io/flatcar/nginx:latest\" returns image reference \"sha256:e8b1cb61bd96acc3ff3c695318c9cc691213d532eee3731d038af92816fcb5f4\"" May 15 11:59:30.341272 containerd[1875]: time="2025-05-15T11:59:30.341240445Z" level=info msg="CreateContainer within sandbox \"7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca\" for container &ContainerMetadata{Name:test,Attempt:0,}" May 15 11:59:30.375984 containerd[1875]: time="2025-05-15T11:59:30.375940055Z" level=info msg="Container 9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955: CDI devices from CRI Config.CDIDevices: []" May 15 11:59:30.403788 containerd[1875]: time="2025-05-15T11:59:30.403746851Z" level=info msg="CreateContainer within sandbox \"7a1e26daf67b06823886c6ab3fb804d80167d2c455765ed6d8b034608e3cb8ca\" for &ContainerMetadata{Name:test,Attempt:0,} returns container id \"9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955\"" May 15 11:59:30.404620 containerd[1875]: time="2025-05-15T11:59:30.404585578Z" level=info msg="StartContainer for \"9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955\"" May 15 11:59:30.405269 containerd[1875]: time="2025-05-15T11:59:30.405249564Z" level=info msg="connecting to shim 9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955" address="unix:///run/containerd/s/b741dd1628e15f208a759460bf53feee03aea5fe677e782c54a70ed7d3ee5d61" protocol=ttrpc version=3 May 15 11:59:30.427731 systemd[1]: Started cri-containerd-9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955.scope - libcontainer container 9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955. May 15 11:59:30.452498 containerd[1875]: time="2025-05-15T11:59:30.452464390Z" level=info msg="StartContainer for \"9a8abc7cafad5d5946abc07179c42d598ad333d4db66296ea85d8336c9ae9955\" returns successfully" May 15 11:59:30.868806 systemd-networkd[1482]: vethf1316db0: Gained IPv6LL May 15 11:59:30.965086 kubelet[2434]: E0515 11:59:30.965039 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:31.121795 kubelet[2434]: I0515 11:59:31.121663 2434 pod_startup_latency_tracker.go:104] "Observed pod startup duration" pod="default/test-pod-1" podStartSLOduration=16.379537711 podStartE2EDuration="17.121647759s" podCreationTimestamp="2025-05-15 11:59:14 +0000 UTC" firstStartedPulling="2025-05-15 11:59:29.597791827 +0000 UTC m=+40.167580108" lastFinishedPulling="2025-05-15 11:59:30.339901875 +0000 UTC m=+40.909690156" observedRunningTime="2025-05-15 11:59:31.121278009 +0000 UTC m=+41.691066290" watchObservedRunningTime="2025-05-15 11:59:31.121647759 +0000 UTC m=+41.691436040" May 15 11:59:31.966528 kubelet[2434]: E0515 11:59:31.966483 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:32.967164 kubelet[2434]: E0515 11:59:32.967121 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:33.968019 kubelet[2434]: E0515 11:59:33.967961 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:34.968260 kubelet[2434]: E0515 11:59:34.968214 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:35.968977 kubelet[2434]: E0515 11:59:35.968935 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:36.969481 kubelet[2434]: E0515 11:59:36.969434 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests" May 15 11:59:37.970046 kubelet[2434]: E0515 11:59:37.969986 2434 file_linux.go:61] "Unable to read config path" err="path does not exist, ignoring" path="/etc/kubernetes/manifests"