Oct 28 05:15:13.490967 kernel: Linux version 6.12.54-flatcar (build@pony-truck.infra.kinvolk.io) (x86_64-cros-linux-gnu-gcc (Gentoo Hardened 14.3.1_p20250801 p4) 14.3.1 20250801, GNU ld (Gentoo 2.45 p3) 2.45.0) #1 SMP PREEMPT_DYNAMIC Tue Oct 28 03:19:40 -00 2025 Oct 28 05:15:13.490993 kernel: Command line: BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200 flatcar.first_boot=detected verity.usrhash=449db75fd0bf4f00a7b0da93783dc37f82f4a66df937e11c006397de0369495c Oct 28 05:15:13.491003 kernel: BIOS-provided physical RAM map: Oct 28 05:15:13.491013 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable Oct 28 05:15:13.491020 kernel: BIOS-e820: [mem 0x0000000000100000-0x00000000007fffff] usable Oct 28 05:15:13.491027 kernel: BIOS-e820: [mem 0x0000000000800000-0x0000000000807fff] ACPI NVS Oct 28 05:15:13.491035 kernel: BIOS-e820: [mem 0x0000000000808000-0x000000000080afff] usable Oct 28 05:15:13.491043 kernel: BIOS-e820: [mem 0x000000000080b000-0x000000000080bfff] ACPI NVS Oct 28 05:15:13.491053 kernel: BIOS-e820: [mem 0x000000000080c000-0x0000000000810fff] usable Oct 28 05:15:13.491061 kernel: BIOS-e820: [mem 0x0000000000811000-0x00000000008fffff] ACPI NVS Oct 28 05:15:13.491068 kernel: BIOS-e820: [mem 0x0000000000900000-0x000000009bd3efff] usable Oct 28 05:15:13.491077 kernel: BIOS-e820: [mem 0x000000009bd3f000-0x000000009bdfffff] reserved Oct 28 05:15:13.491084 kernel: BIOS-e820: [mem 0x000000009be00000-0x000000009c8ecfff] usable Oct 28 05:15:13.491092 kernel: BIOS-e820: [mem 0x000000009c8ed000-0x000000009cb6cfff] reserved Oct 28 05:15:13.491100 kernel: BIOS-e820: [mem 0x000000009cb6d000-0x000000009cb7efff] ACPI data Oct 28 05:15:13.491108 kernel: BIOS-e820: [mem 0x000000009cb7f000-0x000000009cbfefff] ACPI NVS Oct 28 05:15:13.491121 kernel: BIOS-e820: [mem 0x000000009cbff000-0x000000009ce90fff] usable Oct 28 05:15:13.491128 kernel: BIOS-e820: [mem 0x000000009ce91000-0x000000009ce94fff] reserved Oct 28 05:15:13.491136 kernel: BIOS-e820: [mem 0x000000009ce95000-0x000000009ce96fff] ACPI NVS Oct 28 05:15:13.491143 kernel: BIOS-e820: [mem 0x000000009ce97000-0x000000009cedbfff] usable Oct 28 05:15:13.491151 kernel: BIOS-e820: [mem 0x000000009cedc000-0x000000009cf5ffff] reserved Oct 28 05:15:13.491168 kernel: BIOS-e820: [mem 0x000000009cf60000-0x000000009cffffff] ACPI NVS Oct 28 05:15:13.491175 kernel: BIOS-e820: [mem 0x00000000e0000000-0x00000000efffffff] reserved Oct 28 05:15:13.491183 kernel: BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved Oct 28 05:15:13.491191 kernel: BIOS-e820: [mem 0x00000000ffc00000-0x00000000ffffffff] reserved Oct 28 05:15:13.491198 kernel: BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved Oct 28 05:15:13.491208 kernel: NX (Execute Disable) protection: active Oct 28 05:15:13.491216 kernel: APIC: Static calls initialized Oct 28 05:15:13.491224 kernel: e820: update [mem 0x9b320018-0x9b329c57] usable ==> usable Oct 28 05:15:13.491231 kernel: e820: update [mem 0x9b2e3018-0x9b31fe57] usable ==> usable Oct 28 05:15:13.491239 kernel: extended physical RAM map: Oct 28 05:15:13.491247 kernel: reserve setup_data: [mem 0x0000000000000000-0x000000000009ffff] usable Oct 28 05:15:13.491254 kernel: reserve setup_data: [mem 0x0000000000100000-0x00000000007fffff] usable Oct 28 05:15:13.491262 kernel: reserve setup_data: [mem 0x0000000000800000-0x0000000000807fff] ACPI NVS Oct 28 05:15:13.491269 kernel: reserve setup_data: [mem 0x0000000000808000-0x000000000080afff] usable Oct 28 05:15:13.491277 kernel: reserve setup_data: [mem 0x000000000080b000-0x000000000080bfff] ACPI NVS Oct 28 05:15:13.491285 kernel: reserve setup_data: [mem 0x000000000080c000-0x0000000000810fff] usable Oct 28 05:15:13.491295 kernel: reserve setup_data: [mem 0x0000000000811000-0x00000000008fffff] ACPI NVS Oct 28 05:15:13.491302 kernel: reserve setup_data: [mem 0x0000000000900000-0x000000009b2e3017] usable Oct 28 05:15:13.491310 kernel: reserve setup_data: [mem 0x000000009b2e3018-0x000000009b31fe57] usable Oct 28 05:15:13.491321 kernel: reserve setup_data: [mem 0x000000009b31fe58-0x000000009b320017] usable Oct 28 05:15:13.491331 kernel: reserve setup_data: [mem 0x000000009b320018-0x000000009b329c57] usable Oct 28 05:15:13.491339 kernel: reserve setup_data: [mem 0x000000009b329c58-0x000000009bd3efff] usable Oct 28 05:15:13.491346 kernel: reserve setup_data: [mem 0x000000009bd3f000-0x000000009bdfffff] reserved Oct 28 05:15:13.491354 kernel: reserve setup_data: [mem 0x000000009be00000-0x000000009c8ecfff] usable Oct 28 05:15:13.491362 kernel: reserve setup_data: [mem 0x000000009c8ed000-0x000000009cb6cfff] reserved Oct 28 05:15:13.491370 kernel: reserve setup_data: [mem 0x000000009cb6d000-0x000000009cb7efff] ACPI data Oct 28 05:15:13.491378 kernel: reserve setup_data: [mem 0x000000009cb7f000-0x000000009cbfefff] ACPI NVS Oct 28 05:15:13.491386 kernel: reserve setup_data: [mem 0x000000009cbff000-0x000000009ce90fff] usable Oct 28 05:15:13.491394 kernel: reserve setup_data: [mem 0x000000009ce91000-0x000000009ce94fff] reserved Oct 28 05:15:13.491405 kernel: reserve setup_data: [mem 0x000000009ce95000-0x000000009ce96fff] ACPI NVS Oct 28 05:15:13.491413 kernel: reserve setup_data: [mem 0x000000009ce97000-0x000000009cedbfff] usable Oct 28 05:15:13.491434 kernel: reserve setup_data: [mem 0x000000009cedc000-0x000000009cf5ffff] reserved Oct 28 05:15:13.491442 kernel: reserve setup_data: [mem 0x000000009cf60000-0x000000009cffffff] ACPI NVS Oct 28 05:15:13.491450 kernel: reserve setup_data: [mem 0x00000000e0000000-0x00000000efffffff] reserved Oct 28 05:15:13.491458 kernel: reserve setup_data: [mem 0x00000000feffc000-0x00000000feffffff] reserved Oct 28 05:15:13.491466 kernel: reserve setup_data: [mem 0x00000000ffc00000-0x00000000ffffffff] reserved Oct 28 05:15:13.491473 kernel: reserve setup_data: [mem 0x000000fd00000000-0x000000ffffffffff] reserved Oct 28 05:15:13.491483 kernel: efi: EFI v2.7 by EDK II Oct 28 05:15:13.491492 kernel: efi: SMBIOS=0x9c988000 ACPI=0x9cb7e000 ACPI 2.0=0x9cb7e014 MEMATTR=0x9b9e4198 RNG=0x9cb73018 Oct 28 05:15:13.491500 kernel: random: crng init done Oct 28 05:15:13.491512 kernel: efi: Remove mem151: MMIO range=[0xffc00000-0xffffffff] (4MB) from e820 map Oct 28 05:15:13.491520 kernel: e820: remove [mem 0xffc00000-0xffffffff] reserved Oct 28 05:15:13.491530 kernel: secureboot: Secure boot disabled Oct 28 05:15:13.491538 kernel: SMBIOS 2.8 present. Oct 28 05:15:13.491546 kernel: DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS unknown 02/02/2022 Oct 28 05:15:13.491553 kernel: DMI: Memory slots populated: 1/1 Oct 28 05:15:13.491561 kernel: Hypervisor detected: KVM Oct 28 05:15:13.491569 kernel: last_pfn = 0x9cedc max_arch_pfn = 0x400000000 Oct 28 05:15:13.491577 kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00 Oct 28 05:15:13.491585 kernel: kvm-clock: using sched offset of 4900637608 cycles Oct 28 05:15:13.491594 kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns Oct 28 05:15:13.491605 kernel: tsc: Detected 2794.748 MHz processor Oct 28 05:15:13.491614 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Oct 28 05:15:13.491622 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Oct 28 05:15:13.491630 kernel: last_pfn = 0x9cedc max_arch_pfn = 0x400000000 Oct 28 05:15:13.491638 kernel: MTRR map: 4 entries (2 fixed + 2 variable; max 18), built from 8 variable MTRRs Oct 28 05:15:13.491646 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Oct 28 05:15:13.491654 kernel: Using GB pages for direct mapping Oct 28 05:15:13.491665 kernel: ACPI: Early table checksum verification disabled Oct 28 05:15:13.491673 kernel: ACPI: RSDP 0x000000009CB7E014 000024 (v02 BOCHS ) Oct 28 05:15:13.491682 kernel: ACPI: XSDT 0x000000009CB7D0E8 000054 (v01 BOCHS BXPC 00000001 01000013) Oct 28 05:15:13.491690 kernel: ACPI: FACP 0x000000009CB79000 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491698 kernel: ACPI: DSDT 0x000000009CB7A000 0021BA (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491706 kernel: ACPI: FACS 0x000000009CBDD000 000040 Oct 28 05:15:13.491715 kernel: ACPI: APIC 0x000000009CB78000 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491725 kernel: ACPI: HPET 0x000000009CB77000 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491733 kernel: ACPI: MCFG 0x000000009CB76000 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491742 kernel: ACPI: WAET 0x000000009CB75000 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 28 05:15:13.491750 kernel: ACPI: BGRT 0x000000009CB74000 000038 (v01 INTEL EDK2 00000002 01000013) Oct 28 05:15:13.491758 kernel: ACPI: Reserving FACP table memory at [mem 0x9cb79000-0x9cb790f3] Oct 28 05:15:13.491767 kernel: ACPI: Reserving DSDT table memory at [mem 0x9cb7a000-0x9cb7c1b9] Oct 28 05:15:13.491787 kernel: ACPI: Reserving FACS table memory at [mem 0x9cbdd000-0x9cbdd03f] Oct 28 05:15:13.491809 kernel: ACPI: Reserving APIC table memory at [mem 0x9cb78000-0x9cb7808f] Oct 28 05:15:13.491817 kernel: ACPI: Reserving HPET table memory at [mem 0x9cb77000-0x9cb77037] Oct 28 05:15:13.491825 kernel: ACPI: Reserving MCFG table memory at [mem 0x9cb76000-0x9cb7603b] Oct 28 05:15:13.491833 kernel: ACPI: Reserving WAET table memory at [mem 0x9cb75000-0x9cb75027] Oct 28 05:15:13.491842 kernel: ACPI: Reserving BGRT table memory at [mem 0x9cb74000-0x9cb74037] Oct 28 05:15:13.491850 kernel: No NUMA configuration found Oct 28 05:15:13.491858 kernel: Faking a node at [mem 0x0000000000000000-0x000000009cedbfff] Oct 28 05:15:13.491866 kernel: NODE_DATA(0) allocated [mem 0x9ce36dc0-0x9ce3dfff] Oct 28 05:15:13.491877 kernel: Zone ranges: Oct 28 05:15:13.491885 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Oct 28 05:15:13.491894 kernel: DMA32 [mem 0x0000000001000000-0x000000009cedbfff] Oct 28 05:15:13.491902 kernel: Normal empty Oct 28 05:15:13.491910 kernel: Device empty Oct 28 05:15:13.491918 kernel: Movable zone start for each node Oct 28 05:15:13.491926 kernel: Early memory node ranges Oct 28 05:15:13.491936 kernel: node 0: [mem 0x0000000000001000-0x000000000009ffff] Oct 28 05:15:13.491947 kernel: node 0: [mem 0x0000000000100000-0x00000000007fffff] Oct 28 05:15:13.491955 kernel: node 0: [mem 0x0000000000808000-0x000000000080afff] Oct 28 05:15:13.491963 kernel: node 0: [mem 0x000000000080c000-0x0000000000810fff] Oct 28 05:15:13.491971 kernel: node 0: [mem 0x0000000000900000-0x000000009bd3efff] Oct 28 05:15:13.491979 kernel: node 0: [mem 0x000000009be00000-0x000000009c8ecfff] Oct 28 05:15:13.491987 kernel: node 0: [mem 0x000000009cbff000-0x000000009ce90fff] Oct 28 05:15:13.491996 kernel: node 0: [mem 0x000000009ce97000-0x000000009cedbfff] Oct 28 05:15:13.492008 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000009cedbfff] Oct 28 05:15:13.492016 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Oct 28 05:15:13.492032 kernel: On node 0, zone DMA: 96 pages in unavailable ranges Oct 28 05:15:13.492043 kernel: On node 0, zone DMA: 8 pages in unavailable ranges Oct 28 05:15:13.492051 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Oct 28 05:15:13.492060 kernel: On node 0, zone DMA: 239 pages in unavailable ranges Oct 28 05:15:13.492068 kernel: On node 0, zone DMA32: 193 pages in unavailable ranges Oct 28 05:15:13.492077 kernel: On node 0, zone DMA32: 786 pages in unavailable ranges Oct 28 05:15:13.492085 kernel: On node 0, zone DMA32: 6 pages in unavailable ranges Oct 28 05:15:13.492096 kernel: On node 0, zone DMA32: 12580 pages in unavailable ranges Oct 28 05:15:13.492104 kernel: ACPI: PM-Timer IO Port: 0x608 Oct 28 05:15:13.492113 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Oct 28 05:15:13.492121 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Oct 28 05:15:13.492132 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Oct 28 05:15:13.492141 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Oct 28 05:15:13.492149 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Oct 28 05:15:13.492166 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Oct 28 05:15:13.492175 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Oct 28 05:15:13.492183 kernel: ACPI: Using ACPI (MADT) for SMP configuration information Oct 28 05:15:13.492192 kernel: ACPI: HPET id: 0x8086a201 base: 0xfed00000 Oct 28 05:15:13.492202 kernel: TSC deadline timer available Oct 28 05:15:13.492211 kernel: CPU topo: Max. logical packages: 1 Oct 28 05:15:13.492220 kernel: CPU topo: Max. logical dies: 1 Oct 28 05:15:13.492228 kernel: CPU topo: Max. dies per package: 1 Oct 28 05:15:13.492237 kernel: CPU topo: Max. threads per core: 1 Oct 28 05:15:13.492245 kernel: CPU topo: Num. cores per package: 4 Oct 28 05:15:13.492254 kernel: CPU topo: Num. threads per package: 4 Oct 28 05:15:13.492262 kernel: CPU topo: Allowing 4 present CPUs plus 0 hotplug CPUs Oct 28 05:15:13.492273 kernel: kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() Oct 28 05:15:13.492281 kernel: kvm-guest: KVM setup pv remote TLB flush Oct 28 05:15:13.492290 kernel: kvm-guest: setup PV sched yield Oct 28 05:15:13.492298 kernel: [mem 0x9d000000-0xdfffffff] available for PCI devices Oct 28 05:15:13.492306 kernel: Booting paravirtualized kernel on KVM Oct 28 05:15:13.492315 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns Oct 28 05:15:13.492324 kernel: setup_percpu: NR_CPUS:512 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 Oct 28 05:15:13.492335 kernel: percpu: Embedded 60 pages/cpu s207832 r8192 d29736 u524288 Oct 28 05:15:13.492343 kernel: pcpu-alloc: s207832 r8192 d29736 u524288 alloc=1*2097152 Oct 28 05:15:13.492351 kernel: pcpu-alloc: [0] 0 1 2 3 Oct 28 05:15:13.492360 kernel: kvm-guest: PV spinlocks enabled Oct 28 05:15:13.492368 kernel: PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) Oct 28 05:15:13.492381 kernel: Kernel command line: rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200 flatcar.first_boot=detected verity.usrhash=449db75fd0bf4f00a7b0da93783dc37f82f4a66df937e11c006397de0369495c Oct 28 05:15:13.492392 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Oct 28 05:15:13.492401 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Oct 28 05:15:13.492409 kernel: Fallback order for Node 0: 0 Oct 28 05:15:13.492418 kernel: Built 1 zonelists, mobility grouping on. Total pages: 641450 Oct 28 05:15:13.492445 kernel: Policy zone: DMA32 Oct 28 05:15:13.492454 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Oct 28 05:15:13.492462 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Oct 28 05:15:13.492474 kernel: ftrace: allocating 40092 entries in 157 pages Oct 28 05:15:13.492482 kernel: ftrace: allocated 157 pages with 5 groups Oct 28 05:15:13.492491 kernel: Dynamic Preempt: voluntary Oct 28 05:15:13.492499 kernel: rcu: Preemptible hierarchical RCU implementation. Oct 28 05:15:13.492508 kernel: rcu: RCU event tracing is enabled. Oct 28 05:15:13.492518 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Oct 28 05:15:13.492528 kernel: Trampoline variant of Tasks RCU enabled. Oct 28 05:15:13.492537 kernel: Rude variant of Tasks RCU enabled. Oct 28 05:15:13.492550 kernel: Tracing variant of Tasks RCU enabled. Oct 28 05:15:13.492559 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Oct 28 05:15:13.492567 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Oct 28 05:15:13.492578 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Oct 28 05:15:13.492587 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Oct 28 05:15:13.492596 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Oct 28 05:15:13.492604 kernel: NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16 Oct 28 05:15:13.492615 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Oct 28 05:15:13.492623 kernel: Console: colour dummy device 80x25 Oct 28 05:15:13.492632 kernel: printk: legacy console [ttyS0] enabled Oct 28 05:15:13.492640 kernel: ACPI: Core revision 20240827 Oct 28 05:15:13.492649 kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns Oct 28 05:15:13.492657 kernel: APIC: Switch to symmetric I/O mode setup Oct 28 05:15:13.492666 kernel: x2apic enabled Oct 28 05:15:13.492676 kernel: APIC: Switched APIC routing to: physical x2apic Oct 28 05:15:13.492685 kernel: kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() Oct 28 05:15:13.492693 kernel: kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() Oct 28 05:15:13.492702 kernel: kvm-guest: setup PV IPIs Oct 28 05:15:13.492710 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Oct 28 05:15:13.492719 kernel: clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x2848df6a9de, max_idle_ns: 440795280912 ns Oct 28 05:15:13.492727 kernel: Calibrating delay loop (skipped) preset value.. 5589.49 BogoMIPS (lpj=2794748) Oct 28 05:15:13.492738 kernel: x86/cpu: User Mode Instruction Prevention (UMIP) activated Oct 28 05:15:13.492746 kernel: Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 Oct 28 05:15:13.492755 kernel: Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 Oct 28 05:15:13.492763 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Oct 28 05:15:13.492772 kernel: Spectre V2 : Mitigation: Retpolines Oct 28 05:15:13.492780 kernel: Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT Oct 28 05:15:13.492789 kernel: Spectre V2 : Enabling Speculation Barrier for firmware calls Oct 28 05:15:13.492799 kernel: active return thunk: retbleed_return_thunk Oct 28 05:15:13.492808 kernel: RETBleed: Mitigation: untrained return thunk Oct 28 05:15:13.492819 kernel: Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier Oct 28 05:15:13.492828 kernel: Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl Oct 28 05:15:13.492837 kernel: Speculative Return Stack Overflow: IBPB-extending microcode not applied! Oct 28 05:15:13.492846 kernel: Speculative Return Stack Overflow: WARNING: See https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for mitigation options. Oct 28 05:15:13.492854 kernel: active return thunk: srso_return_thunk Oct 28 05:15:13.492865 kernel: Speculative Return Stack Overflow: Vulnerable: Safe RET, no microcode Oct 28 05:15:13.492874 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Oct 28 05:15:13.492882 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Oct 28 05:15:13.492891 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Oct 28 05:15:13.492899 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Oct 28 05:15:13.492908 kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. Oct 28 05:15:13.492916 kernel: Freeing SMP alternatives memory: 32K Oct 28 05:15:13.492927 kernel: pid_max: default: 32768 minimum: 301 Oct 28 05:15:13.492935 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,ima Oct 28 05:15:13.492943 kernel: landlock: Up and running. Oct 28 05:15:13.492952 kernel: SELinux: Initializing. Oct 28 05:15:13.492960 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 28 05:15:13.492969 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 28 05:15:13.492978 kernel: smpboot: CPU0: AMD EPYC 7402P 24-Core Processor (family: 0x17, model: 0x31, stepping: 0x0) Oct 28 05:15:13.492988 kernel: Performance Events: Fam17h+ core perfctr, AMD PMU driver. Oct 28 05:15:13.492997 kernel: ... version: 0 Oct 28 05:15:13.493005 kernel: ... bit width: 48 Oct 28 05:15:13.493013 kernel: ... generic registers: 6 Oct 28 05:15:13.493022 kernel: ... value mask: 0000ffffffffffff Oct 28 05:15:13.493030 kernel: ... max period: 00007fffffffffff Oct 28 05:15:13.493039 kernel: ... fixed-purpose events: 0 Oct 28 05:15:13.493050 kernel: ... event mask: 000000000000003f Oct 28 05:15:13.493058 kernel: signal: max sigframe size: 1776 Oct 28 05:15:13.493066 kernel: rcu: Hierarchical SRCU implementation. Oct 28 05:15:13.493075 kernel: rcu: Max phase no-delay instances is 400. Oct 28 05:15:13.493086 kernel: Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level Oct 28 05:15:13.493095 kernel: smp: Bringing up secondary CPUs ... Oct 28 05:15:13.493103 kernel: smpboot: x86: Booting SMP configuration: Oct 28 05:15:13.493114 kernel: .... node #0, CPUs: #1 #2 #3 Oct 28 05:15:13.493122 kernel: smp: Brought up 1 node, 4 CPUs Oct 28 05:15:13.493131 kernel: smpboot: Total of 4 processors activated (22357.98 BogoMIPS) Oct 28 05:15:13.493139 kernel: Memory: 2441088K/2565800K available (14336K kernel code, 2443K rwdata, 29892K rodata, 15960K init, 2084K bss, 118772K reserved, 0K cma-reserved) Oct 28 05:15:13.493148 kernel: devtmpfs: initialized Oct 28 05:15:13.493163 kernel: x86/mm: Memory block size: 128MB Oct 28 05:15:13.493172 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00800000-0x00807fff] (32768 bytes) Oct 28 05:15:13.493183 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x0080b000-0x0080bfff] (4096 bytes) Oct 28 05:15:13.493191 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00811000-0x008fffff] (978944 bytes) Oct 28 05:15:13.493200 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cb7f000-0x9cbfefff] (524288 bytes) Oct 28 05:15:13.493208 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9ce95000-0x9ce96fff] (8192 bytes) Oct 28 05:15:13.493217 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cf60000-0x9cffffff] (655360 bytes) Oct 28 05:15:13.493227 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Oct 28 05:15:13.493235 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Oct 28 05:15:13.493246 kernel: pinctrl core: initialized pinctrl subsystem Oct 28 05:15:13.493254 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Oct 28 05:15:13.493263 kernel: audit: initializing netlink subsys (disabled) Oct 28 05:15:13.493271 kernel: audit: type=2000 audit(1761628510.958:1): state=initialized audit_enabled=0 res=1 Oct 28 05:15:13.493280 kernel: thermal_sys: Registered thermal governor 'step_wise' Oct 28 05:15:13.493288 kernel: thermal_sys: Registered thermal governor 'user_space' Oct 28 05:15:13.493297 kernel: cpuidle: using governor menu Oct 28 05:15:13.493307 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Oct 28 05:15:13.493316 kernel: dca service started, version 1.12.1 Oct 28 05:15:13.493324 kernel: PCI: ECAM [mem 0xe0000000-0xefffffff] (base 0xe0000000) for domain 0000 [bus 00-ff] Oct 28 05:15:13.493333 kernel: PCI: Using configuration type 1 for base access Oct 28 05:15:13.493341 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Oct 28 05:15:13.493350 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Oct 28 05:15:13.493358 kernel: HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page Oct 28 05:15:13.493369 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Oct 28 05:15:13.493378 kernel: HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page Oct 28 05:15:13.493386 kernel: ACPI: Added _OSI(Module Device) Oct 28 05:15:13.493394 kernel: ACPI: Added _OSI(Processor Device) Oct 28 05:15:13.493403 kernel: ACPI: Added _OSI(Processor Aggregator Device) Oct 28 05:15:13.493411 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Oct 28 05:15:13.493466 kernel: ACPI: Interpreter enabled Oct 28 05:15:13.493476 kernel: ACPI: PM: (supports S0 S3 S5) Oct 28 05:15:13.493488 kernel: ACPI: Using IOAPIC for interrupt routing Oct 28 05:15:13.493496 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Oct 28 05:15:13.493505 kernel: PCI: Using E820 reservations for host bridge windows Oct 28 05:15:13.493513 kernel: ACPI: Enabled 2 GPEs in block 00 to 3F Oct 28 05:15:13.493522 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Oct 28 05:15:13.493776 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Oct 28 05:15:13.493965 kernel: acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR] Oct 28 05:15:13.494145 kernel: acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability] Oct 28 05:15:13.494164 kernel: PCI host bridge to bus 0000:00 Oct 28 05:15:13.494342 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Oct 28 05:15:13.494524 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Oct 28 05:15:13.494685 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Oct 28 05:15:13.494851 kernel: pci_bus 0000:00: root bus resource [mem 0x9d000000-0xdfffffff window] Oct 28 05:15:13.495012 kernel: pci_bus 0000:00: root bus resource [mem 0xf0000000-0xfebfffff window] Oct 28 05:15:13.495180 kernel: pci_bus 0000:00: root bus resource [mem 0x380000000000-0x3807ffffffff window] Oct 28 05:15:13.495342 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Oct 28 05:15:13.495555 kernel: pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 conventional PCI endpoint Oct 28 05:15:13.495747 kernel: pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint Oct 28 05:15:13.495922 kernel: pci 0000:00:01.0: BAR 0 [mem 0xc0000000-0xc0ffffff pref] Oct 28 05:15:13.496146 kernel: pci 0000:00:01.0: BAR 2 [mem 0xc1044000-0xc1044fff] Oct 28 05:15:13.496329 kernel: pci 0000:00:01.0: ROM [mem 0xffff0000-0xffffffff pref] Oct 28 05:15:13.496646 kernel: pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Oct 28 05:15:13.496836 kernel: pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint Oct 28 05:15:13.497025 kernel: pci 0000:00:02.0: BAR 0 [io 0x6100-0x611f] Oct 28 05:15:13.497331 kernel: pci 0000:00:02.0: BAR 1 [mem 0xc1043000-0xc1043fff] Oct 28 05:15:13.497571 kernel: pci 0000:00:02.0: BAR 4 [mem 0x380000000000-0x380000003fff 64bit pref] Oct 28 05:15:13.497763 kernel: pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint Oct 28 05:15:13.497940 kernel: pci 0000:00:03.0: BAR 0 [io 0x6000-0x607f] Oct 28 05:15:13.498121 kernel: pci 0000:00:03.0: BAR 1 [mem 0xc1042000-0xc1042fff] Oct 28 05:15:13.498307 kernel: pci 0000:00:03.0: BAR 4 [mem 0x380000004000-0x380000007fff 64bit pref] Oct 28 05:15:13.498508 kernel: pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint Oct 28 05:15:13.498684 kernel: pci 0000:00:04.0: BAR 0 [io 0x60e0-0x60ff] Oct 28 05:15:13.498858 kernel: pci 0000:00:04.0: BAR 1 [mem 0xc1041000-0xc1041fff] Oct 28 05:15:13.499031 kernel: pci 0000:00:04.0: BAR 4 [mem 0x380000008000-0x38000000bfff 64bit pref] Oct 28 05:15:13.499229 kernel: pci 0000:00:04.0: ROM [mem 0xfffc0000-0xffffffff pref] Oct 28 05:15:13.499413 kernel: pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 conventional PCI endpoint Oct 28 05:15:13.499612 kernel: pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO Oct 28 05:15:13.499966 kernel: pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 conventional PCI endpoint Oct 28 05:15:13.500141 kernel: pci 0000:00:1f.2: BAR 4 [io 0x60c0-0x60df] Oct 28 05:15:13.500325 kernel: pci 0000:00:1f.2: BAR 5 [mem 0xc1040000-0xc1040fff] Oct 28 05:15:13.500531 kernel: pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 conventional PCI endpoint Oct 28 05:15:13.500707 kernel: pci 0000:00:1f.3: BAR 4 [io 0x6080-0x60bf] Oct 28 05:15:13.500720 kernel: ACPI: PCI: Interrupt link LNKA configured for IRQ 10 Oct 28 05:15:13.500729 kernel: ACPI: PCI: Interrupt link LNKB configured for IRQ 10 Oct 28 05:15:13.500738 kernel: ACPI: PCI: Interrupt link LNKC configured for IRQ 11 Oct 28 05:15:13.500746 kernel: ACPI: PCI: Interrupt link LNKD configured for IRQ 11 Oct 28 05:15:13.500759 kernel: ACPI: PCI: Interrupt link LNKE configured for IRQ 10 Oct 28 05:15:13.500768 kernel: ACPI: PCI: Interrupt link LNKF configured for IRQ 10 Oct 28 05:15:13.500776 kernel: ACPI: PCI: Interrupt link LNKG configured for IRQ 11 Oct 28 05:15:13.500785 kernel: ACPI: PCI: Interrupt link LNKH configured for IRQ 11 Oct 28 05:15:13.500793 kernel: ACPI: PCI: Interrupt link GSIA configured for IRQ 16 Oct 28 05:15:13.500802 kernel: ACPI: PCI: Interrupt link GSIB configured for IRQ 17 Oct 28 05:15:13.500810 kernel: ACPI: PCI: Interrupt link GSIC configured for IRQ 18 Oct 28 05:15:13.500821 kernel: ACPI: PCI: Interrupt link GSID configured for IRQ 19 Oct 28 05:15:13.500830 kernel: ACPI: PCI: Interrupt link GSIE configured for IRQ 20 Oct 28 05:15:13.500838 kernel: ACPI: PCI: Interrupt link GSIF configured for IRQ 21 Oct 28 05:15:13.500847 kernel: ACPI: PCI: Interrupt link GSIG configured for IRQ 22 Oct 28 05:15:13.500855 kernel: ACPI: PCI: Interrupt link GSIH configured for IRQ 23 Oct 28 05:15:13.500864 kernel: iommu: Default domain type: Translated Oct 28 05:15:13.500872 kernel: iommu: DMA domain TLB invalidation policy: lazy mode Oct 28 05:15:13.500883 kernel: efivars: Registered efivars operations Oct 28 05:15:13.500892 kernel: PCI: Using ACPI for IRQ routing Oct 28 05:15:13.500900 kernel: PCI: pci_cache_line_size set to 64 bytes Oct 28 05:15:13.500909 kernel: e820: reserve RAM buffer [mem 0x0080b000-0x008fffff] Oct 28 05:15:13.500917 kernel: e820: reserve RAM buffer [mem 0x00811000-0x008fffff] Oct 28 05:15:13.500926 kernel: e820: reserve RAM buffer [mem 0x9b2e3018-0x9bffffff] Oct 28 05:15:13.500934 kernel: e820: reserve RAM buffer [mem 0x9b320018-0x9bffffff] Oct 28 05:15:13.500945 kernel: e820: reserve RAM buffer [mem 0x9bd3f000-0x9bffffff] Oct 28 05:15:13.500953 kernel: e820: reserve RAM buffer [mem 0x9c8ed000-0x9fffffff] Oct 28 05:15:13.500962 kernel: e820: reserve RAM buffer [mem 0x9ce91000-0x9fffffff] Oct 28 05:15:13.500970 kernel: e820: reserve RAM buffer [mem 0x9cedc000-0x9fffffff] Oct 28 05:15:13.501145 kernel: pci 0000:00:01.0: vgaarb: setting as boot VGA device Oct 28 05:15:13.501329 kernel: pci 0000:00:01.0: vgaarb: bridge control possible Oct 28 05:15:13.501531 kernel: pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Oct 28 05:15:13.501545 kernel: vgaarb: loaded Oct 28 05:15:13.501556 kernel: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Oct 28 05:15:13.501565 kernel: hpet0: 3 comparators, 64-bit 100.000000 MHz counter Oct 28 05:15:13.501574 kernel: clocksource: Switched to clocksource kvm-clock Oct 28 05:15:13.501582 kernel: VFS: Disk quotas dquot_6.6.0 Oct 28 05:15:13.501591 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Oct 28 05:15:13.501599 kernel: pnp: PnP ACPI init Oct 28 05:15:13.501801 kernel: system 00:05: [mem 0xe0000000-0xefffffff window] has been reserved Oct 28 05:15:13.501817 kernel: pnp: PnP ACPI: found 6 devices Oct 28 05:15:13.501826 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Oct 28 05:15:13.501835 kernel: NET: Registered PF_INET protocol family Oct 28 05:15:13.501844 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Oct 28 05:15:13.501853 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Oct 28 05:15:13.501864 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Oct 28 05:15:13.501875 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Oct 28 05:15:13.501884 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Oct 28 05:15:13.501893 kernel: TCP: Hash tables configured (established 32768 bind 32768) Oct 28 05:15:13.501902 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 28 05:15:13.501911 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 28 05:15:13.501920 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Oct 28 05:15:13.501931 kernel: NET: Registered PF_XDP protocol family Oct 28 05:15:13.502105 kernel: pci 0000:00:04.0: ROM [mem 0xfffc0000-0xffffffff pref]: can't claim; no compatible bridge window Oct 28 05:15:13.502303 kernel: pci 0000:00:04.0: ROM [mem 0x9d000000-0x9d03ffff pref]: assigned Oct 28 05:15:13.502482 kernel: pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] Oct 28 05:15:13.502645 kernel: pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] Oct 28 05:15:13.502805 kernel: pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] Oct 28 05:15:13.502970 kernel: pci_bus 0000:00: resource 7 [mem 0x9d000000-0xdfffffff window] Oct 28 05:15:13.503129 kernel: pci_bus 0000:00: resource 8 [mem 0xf0000000-0xfebfffff window] Oct 28 05:15:13.503300 kernel: pci_bus 0000:00: resource 9 [mem 0x380000000000-0x3807ffffffff window] Oct 28 05:15:13.503312 kernel: PCI: CLS 0 bytes, default 64 Oct 28 05:15:13.503321 kernel: clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2848df6a9de, max_idle_ns: 440795280912 ns Oct 28 05:15:13.503336 kernel: Initialise system trusted keyrings Oct 28 05:15:13.503345 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Oct 28 05:15:13.503354 kernel: Key type asymmetric registered Oct 28 05:15:13.503362 kernel: Asymmetric key parser 'x509' registered Oct 28 05:15:13.503372 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) Oct 28 05:15:13.503380 kernel: io scheduler mq-deadline registered Oct 28 05:15:13.503390 kernel: io scheduler kyber registered Oct 28 05:15:13.503400 kernel: io scheduler bfq registered Oct 28 05:15:13.503409 kernel: ioatdma: Intel(R) QuickData Technology Driver 5.00 Oct 28 05:15:13.503435 kernel: ACPI: \_SB_.GSIG: Enabled at IRQ 22 Oct 28 05:15:13.503445 kernel: ACPI: \_SB_.GSIH: Enabled at IRQ 23 Oct 28 05:15:13.503454 kernel: ACPI: \_SB_.GSIE: Enabled at IRQ 20 Oct 28 05:15:13.503462 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Oct 28 05:15:13.503471 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Oct 28 05:15:13.503483 kernel: i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Oct 28 05:15:13.503492 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Oct 28 05:15:13.503501 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Oct 28 05:15:13.503688 kernel: rtc_cmos 00:04: RTC can wake from S4 Oct 28 05:15:13.503702 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 Oct 28 05:15:13.503868 kernel: rtc_cmos 00:04: registered as rtc0 Oct 28 05:15:13.504040 kernel: rtc_cmos 00:04: setting system clock to 2025-10-28T05:15:11 UTC (1761628511) Oct 28 05:15:13.504219 kernel: rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram Oct 28 05:15:13.504231 kernel: amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled Oct 28 05:15:13.504240 kernel: efifb: probing for efifb Oct 28 05:15:13.504249 kernel: efifb: framebuffer at 0xc0000000, using 4000k, total 4000k Oct 28 05:15:13.504258 kernel: efifb: mode is 1280x800x32, linelength=5120, pages=1 Oct 28 05:15:13.504267 kernel: efifb: scrolling: redraw Oct 28 05:15:13.504279 kernel: efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0 Oct 28 05:15:13.504288 kernel: Console: switching to colour frame buffer device 160x50 Oct 28 05:15:13.504296 kernel: fb0: EFI VGA frame buffer device Oct 28 05:15:13.504305 kernel: pstore: Using crash dump compression: deflate Oct 28 05:15:13.504314 kernel: pstore: Registered efi_pstore as persistent store backend Oct 28 05:15:13.504323 kernel: NET: Registered PF_INET6 protocol family Oct 28 05:15:13.504332 kernel: Segment Routing with IPv6 Oct 28 05:15:13.504343 kernel: In-situ OAM (IOAM) with IPv6 Oct 28 05:15:13.504351 kernel: NET: Registered PF_PACKET protocol family Oct 28 05:15:13.504360 kernel: Key type dns_resolver registered Oct 28 05:15:13.504369 kernel: IPI shorthand broadcast: enabled Oct 28 05:15:13.504378 kernel: sched_clock: Marking stable (1460004124, 294518851)->(1827996847, -73473872) Oct 28 05:15:13.504386 kernel: registered taskstats version 1 Oct 28 05:15:13.504395 kernel: Loading compiled-in X.509 certificates Oct 28 05:15:13.504404 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.12.54-flatcar: a9d98af1927e389c63ed03bf44a9f2758bf88a8e' Oct 28 05:15:13.504415 kernel: Demotion targets for Node 0: null Oct 28 05:15:13.504444 kernel: Key type .fscrypt registered Oct 28 05:15:13.504452 kernel: Key type fscrypt-provisioning registered Oct 28 05:15:13.504461 kernel: ima: No TPM chip found, activating TPM-bypass! Oct 28 05:15:13.504470 kernel: ima: Allocated hash algorithm: sha1 Oct 28 05:15:13.504478 kernel: ima: No architecture policies found Oct 28 05:15:13.504487 kernel: clk: Disabling unused clocks Oct 28 05:15:13.504499 kernel: Freeing unused kernel image (initmem) memory: 15960K Oct 28 05:15:13.504510 kernel: Write protecting the kernel read-only data: 45056k Oct 28 05:15:13.504519 kernel: Freeing unused kernel image (rodata/data gap) memory: 828K Oct 28 05:15:13.504528 kernel: Run /init as init process Oct 28 05:15:13.504536 kernel: with arguments: Oct 28 05:15:13.504547 kernel: /init Oct 28 05:15:13.504556 kernel: with environment: Oct 28 05:15:13.504569 kernel: HOME=/ Oct 28 05:15:13.504578 kernel: TERM=linux Oct 28 05:15:13.504587 kernel: SCSI subsystem initialized Oct 28 05:15:13.504596 kernel: libata version 3.00 loaded. Oct 28 05:15:13.504774 kernel: ahci 0000:00:1f.2: version 3.0 Oct 28 05:15:13.504786 kernel: ACPI: \_SB_.GSIA: Enabled at IRQ 16 Oct 28 05:15:13.504974 kernel: ahci 0000:00:1f.2: AHCI vers 0001.0000, 32 command slots, 1.5 Gbps, SATA mode Oct 28 05:15:13.505154 kernel: ahci 0000:00:1f.2: 6/6 ports implemented (port mask 0x3f) Oct 28 05:15:13.505339 kernel: ahci 0000:00:1f.2: flags: 64bit ncq only Oct 28 05:15:13.505568 kernel: scsi host0: ahci Oct 28 05:15:13.505760 kernel: scsi host1: ahci Oct 28 05:15:13.505975 kernel: scsi host2: ahci Oct 28 05:15:13.506179 kernel: scsi host3: ahci Oct 28 05:15:13.506369 kernel: scsi host4: ahci Oct 28 05:15:13.506574 kernel: scsi host5: ahci Oct 28 05:15:13.506588 kernel: ata1: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040100 irq 26 lpm-pol 1 Oct 28 05:15:13.506598 kernel: ata2: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040180 irq 26 lpm-pol 1 Oct 28 05:15:13.506607 kernel: ata3: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040200 irq 26 lpm-pol 1 Oct 28 05:15:13.506620 kernel: ata4: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040280 irq 26 lpm-pol 1 Oct 28 05:15:13.506629 kernel: ata5: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040300 irq 26 lpm-pol 1 Oct 28 05:15:13.506638 kernel: ata6: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040380 irq 26 lpm-pol 1 Oct 28 05:15:13.506648 kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Oct 28 05:15:13.506657 kernel: ata6: SATA link down (SStatus 0 SControl 300) Oct 28 05:15:13.506666 kernel: ata2: SATA link down (SStatus 0 SControl 300) Oct 28 05:15:13.506674 kernel: ata4: SATA link down (SStatus 0 SControl 300) Oct 28 05:15:13.506685 kernel: ata5: SATA link down (SStatus 0 SControl 300) Oct 28 05:15:13.506695 kernel: ata1: SATA link down (SStatus 0 SControl 300) Oct 28 05:15:13.506703 kernel: ata3.00: LPM support broken, forcing max_power Oct 28 05:15:13.506712 kernel: ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 Oct 28 05:15:13.506721 kernel: ata3.00: applying bridge limits Oct 28 05:15:13.506730 kernel: ata3.00: LPM support broken, forcing max_power Oct 28 05:15:13.506738 kernel: ata3.00: configured for UDMA/100 Oct 28 05:15:13.506989 kernel: scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 Oct 28 05:15:13.507221 kernel: virtio_blk virtio1: 4/0/0 default/read/poll queues Oct 28 05:15:13.507397 kernel: virtio_blk virtio1: [vda] 16515072 512-byte logical blocks (8.46 GB/7.88 GiB) Oct 28 05:15:13.507409 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 28 05:15:13.507438 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507634 kernel: sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Oct 28 05:15:13.507652 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Oct 28 05:15:13.507841 kernel: sr 2:0:0:0: Attached scsi CD-ROM sr0 Oct 28 05:15:13.507854 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Oct 28 05:15:13.507863 kernel: device-mapper: uevent: version 1.0.3 Oct 28 05:15:13.507872 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev Oct 28 05:15:13.507881 kernel: device-mapper: verity: sha256 using shash "sha256-generic" Oct 28 05:15:13.507890 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507902 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507910 kernel: raid6: avx2x4 gen() 27914 MB/s Oct 28 05:15:13.507919 kernel: raid6: avx2x2 gen() 30411 MB/s Oct 28 05:15:13.507928 kernel: raid6: avx2x1 gen() 25456 MB/s Oct 28 05:15:13.507937 kernel: raid6: using algorithm avx2x2 gen() 30411 MB/s Oct 28 05:15:13.507946 kernel: raid6: .... xor() 19049 MB/s, rmw enabled Oct 28 05:15:13.507954 kernel: raid6: using avx2x2 recovery algorithm Oct 28 05:15:13.507965 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507976 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507984 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.507993 kernel: xor: automatically using best checksumming function avx Oct 28 05:15:13.508002 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.508011 kernel: Btrfs loaded, zoned=no, fsverity=no Oct 28 05:15:13.508020 kernel: BTRFS: device fsid 98ad3ab2-0171-42ae-a5fc-7be2369f5a89 devid 1 transid 37 /dev/mapper/usr (253:0) scanned by mount (175) Oct 28 05:15:13.508029 kernel: BTRFS info (device dm-0): first mount of filesystem 98ad3ab2-0171-42ae-a5fc-7be2369f5a89 Oct 28 05:15:13.508040 kernel: BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm Oct 28 05:15:13.508049 kernel: BTRFS info (device dm-0): disabling log replay at mount time Oct 28 05:15:13.508058 kernel: BTRFS info (device dm-0): enabling free space tree Oct 28 05:15:13.508067 kernel: Invalid ELF header magic: != \u007fELF Oct 28 05:15:13.508075 kernel: loop: module loaded Oct 28 05:15:13.508084 kernel: loop0: detected capacity change from 0 to 100136 Oct 28 05:15:13.508093 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Oct 28 05:15:13.508105 systemd[1]: Successfully made /usr/ read-only. Oct 28 05:15:13.508117 systemd[1]: systemd 257.7 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +IPE +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 -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) Oct 28 05:15:13.508127 systemd[1]: Detected virtualization kvm. Oct 28 05:15:13.508136 systemd[1]: Detected architecture x86-64. Oct 28 05:15:13.508145 systemd[1]: Running in initrd. Oct 28 05:15:13.508163 systemd[1]: No hostname configured, using default hostname. Oct 28 05:15:13.508175 systemd[1]: Hostname set to . Oct 28 05:15:13.508185 systemd[1]: Initializing machine ID from SMBIOS/DMI UUID. Oct 28 05:15:13.508194 systemd[1]: Queued start job for default target initrd.target. Oct 28 05:15:13.508204 systemd[1]: Unnecessary job was removed for dev-mapper-usr.device - /dev/mapper/usr. Oct 28 05:15:13.508215 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 28 05:15:13.508224 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 28 05:15:13.508236 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Oct 28 05:15:13.508246 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 28 05:15:13.508256 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Oct 28 05:15:13.508266 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Oct 28 05:15:13.508275 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 28 05:15:13.508285 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 28 05:15:13.508297 systemd[1]: Reached target initrd-usr-fs.target - Initrd /usr File System. Oct 28 05:15:13.508306 systemd[1]: Reached target paths.target - Path Units. Oct 28 05:15:13.508315 systemd[1]: Reached target slices.target - Slice Units. Oct 28 05:15:13.508325 systemd[1]: Reached target swap.target - Swaps. Oct 28 05:15:13.508334 systemd[1]: Reached target timers.target - Timer Units. Oct 28 05:15:13.508343 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Oct 28 05:15:13.508353 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 28 05:15:13.508364 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Oct 28 05:15:13.508374 systemd[1]: Listening on systemd-journald.socket - Journal Sockets. Oct 28 05:15:13.508383 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 28 05:15:13.508393 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 28 05:15:13.508403 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 28 05:15:13.508412 systemd[1]: Reached target sockets.target - Socket Units. Oct 28 05:15:13.508437 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Oct 28 05:15:13.508450 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Oct 28 05:15:13.508459 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 28 05:15:13.508468 systemd[1]: Finished network-cleanup.service - Network Cleanup. Oct 28 05:15:13.508478 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). Oct 28 05:15:13.508488 systemd[1]: Starting systemd-fsck-usr.service... Oct 28 05:15:13.508497 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 28 05:15:13.508509 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 28 05:15:13.508518 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 28 05:15:13.508528 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Oct 28 05:15:13.508537 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 28 05:15:13.508549 systemd[1]: Finished systemd-fsck-usr.service. Oct 28 05:15:13.508559 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 28 05:15:13.508685 systemd-journald[311]: Collecting audit messages is disabled. Oct 28 05:15:13.508709 systemd-journald[311]: Journal started Oct 28 05:15:13.508728 systemd-journald[311]: Runtime Journal (/run/log/journal/c48b096d43c04bbe86df3af6f6588e0f) is 6M, max 48.1M, 42.1M free. Oct 28 05:15:13.511476 systemd[1]: Started systemd-journald.service - Journal Service. Oct 28 05:15:13.520458 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Oct 28 05:15:13.523750 systemd-modules-load[313]: Inserted module 'br_netfilter' Oct 28 05:15:13.527387 kernel: Bridge firewalling registered Oct 28 05:15:13.524557 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 28 05:15:13.527654 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 28 05:15:13.542644 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:13.546277 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 28 05:15:13.553858 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 28 05:15:13.557724 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 28 05:15:13.562982 systemd-tmpfiles[329]: /usr/lib/tmpfiles.d/var.conf:14: Duplicate line for path "/var/log", ignoring. Oct 28 05:15:13.568308 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 28 05:15:13.572415 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 28 05:15:13.588210 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 28 05:15:13.589842 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 28 05:15:13.594197 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 28 05:15:13.600010 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Oct 28 05:15:13.604929 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 28 05:15:13.634431 dracut-cmdline[353]: Using kernel command line parameters: rd.driver.pre=btrfs SYSTEMD_SULOGIN_FORCE=1 rootflags=rw mount.usrflags=ro BOOT_IMAGE=/flatcar/vmlinuz-a mount.usr=/dev/mapper/usr verity.usr=PARTUUID=7130c94a-213a-4e5a-8e26-6cce9662f132 rootflags=rw mount.usrflags=ro consoleblank=0 root=LABEL=ROOT console=ttyS0,115200 flatcar.first_boot=detected verity.usrhash=449db75fd0bf4f00a7b0da93783dc37f82f4a66df937e11c006397de0369495c Oct 28 05:15:13.668954 systemd-resolved[354]: Positive Trust Anchors: Oct 28 05:15:13.668972 systemd-resolved[354]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 28 05:15:13.668976 systemd-resolved[354]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 Oct 28 05:15:13.669008 systemd-resolved[354]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 28 05:15:13.685575 systemd-resolved[354]: Defaulting to hostname 'linux'. Oct 28 05:15:13.688184 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 28 05:15:13.690119 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 28 05:15:13.767456 kernel: Loading iSCSI transport class v2.0-870. Oct 28 05:15:13.781459 kernel: iscsi: registered transport (tcp) Oct 28 05:15:13.805040 kernel: iscsi: registered transport (qla4xxx) Oct 28 05:15:13.805074 kernel: QLogic iSCSI HBA Driver Oct 28 05:15:13.833568 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Oct 28 05:15:13.870673 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Oct 28 05:15:13.872663 systemd[1]: Reached target network-pre.target - Preparation for Network. Oct 28 05:15:13.934010 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Oct 28 05:15:13.937540 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Oct 28 05:15:13.939969 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Oct 28 05:15:13.982585 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Oct 28 05:15:13.985007 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 28 05:15:14.014961 systemd-udevd[592]: Using default interface naming scheme 'v257'. Oct 28 05:15:14.029091 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 28 05:15:14.036551 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Oct 28 05:15:14.067028 dracut-pre-trigger[650]: rd.md=0: removing MD RAID activation Oct 28 05:15:14.079557 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 28 05:15:14.082337 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 28 05:15:14.110467 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Oct 28 05:15:14.114555 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 28 05:15:14.140313 systemd-networkd[712]: lo: Link UP Oct 28 05:15:14.140324 systemd-networkd[712]: lo: Gained carrier Oct 28 05:15:14.141044 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 28 05:15:14.143672 systemd[1]: Reached target network.target - Network. Oct 28 05:15:14.214579 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 28 05:15:14.220816 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Oct 28 05:15:14.281532 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Oct 28 05:15:14.297647 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Oct 28 05:15:14.309470 kernel: cryptd: max_cpu_qlen set to 1000 Oct 28 05:15:14.313084 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 28 05:15:14.323030 kernel: AES CTR mode by8 optimization enabled Oct 28 05:15:14.329468 kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3 Oct 28 05:15:14.332161 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Oct 28 05:15:14.376378 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Oct 28 05:15:14.385086 systemd-networkd[712]: eth0: Found matching .network file, based on potentially unpredictable interface name: /usr/lib/systemd/network/zz-default.network Oct 28 05:15:14.385097 systemd-networkd[712]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 28 05:15:14.386514 systemd-networkd[712]: eth0: Link UP Oct 28 05:15:14.386732 systemd-networkd[712]: eth0: Gained carrier Oct 28 05:15:14.386741 systemd-networkd[712]: eth0: Found matching .network file, based on potentially unpredictable interface name: /usr/lib/systemd/network/zz-default.network Oct 28 05:15:14.388527 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 28 05:15:14.388593 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:14.389899 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Oct 28 05:15:14.403323 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 28 05:15:14.410721 systemd-networkd[712]: eth0: DHCPv4 address 10.0.0.72/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 28 05:15:14.432230 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:14.528467 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Oct 28 05:15:14.531332 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Oct 28 05:15:14.532896 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 28 05:15:14.537043 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 28 05:15:14.542772 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Oct 28 05:15:14.577082 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Oct 28 05:15:15.491179 disk-uuid[841]: Warning: The kernel is still using the old partition table. Oct 28 05:15:15.491179 disk-uuid[841]: The new table will be used at the next reboot or after you Oct 28 05:15:15.491179 disk-uuid[841]: run partprobe(8) or kpartx(8) Oct 28 05:15:15.491179 disk-uuid[841]: The operation has completed successfully. Oct 28 05:15:15.503665 systemd[1]: disk-uuid.service: Deactivated successfully. Oct 28 05:15:15.503811 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Oct 28 05:15:15.508749 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Oct 28 05:15:15.555471 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (864) Oct 28 05:15:15.558701 kernel: BTRFS info (device vda6): first mount of filesystem 7acd037c-32ce-4796-90d6-101869832417 Oct 28 05:15:15.558734 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 28 05:15:15.562613 kernel: BTRFS info (device vda6): turning on async discard Oct 28 05:15:15.562638 kernel: BTRFS info (device vda6): enabling free space tree Oct 28 05:15:15.570454 kernel: BTRFS info (device vda6): last unmount of filesystem 7acd037c-32ce-4796-90d6-101869832417 Oct 28 05:15:15.571557 systemd[1]: Finished ignition-setup.service - Ignition (setup). Oct 28 05:15:15.574595 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Oct 28 05:15:15.696439 ignition[883]: Ignition 2.22.0 Oct 28 05:15:15.696453 ignition[883]: Stage: fetch-offline Oct 28 05:15:15.696494 ignition[883]: no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:15.696506 ignition[883]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:15.696599 ignition[883]: parsed url from cmdline: "" Oct 28 05:15:15.696604 ignition[883]: no config URL provided Oct 28 05:15:15.696609 ignition[883]: reading system config file "/usr/lib/ignition/user.ign" Oct 28 05:15:15.696621 ignition[883]: no config at "/usr/lib/ignition/user.ign" Oct 28 05:15:15.696669 ignition[883]: op(1): [started] loading QEMU firmware config module Oct 28 05:15:15.696674 ignition[883]: op(1): executing: "modprobe" "qemu_fw_cfg" Oct 28 05:15:15.708230 ignition[883]: op(1): [finished] loading QEMU firmware config module Oct 28 05:15:15.709397 ignition[883]: parsing config with SHA512: 81aa9e4d65d7de3cd558ecf607f367fcbb15e3957369bf46abfe87e31f918057bfc799eefeff8e72c1d58b761d63a4fb75681e9f893c73181be3aefedf642cd7 Oct 28 05:15:15.715645 unknown[883]: fetched base config from "system" Oct 28 05:15:15.715658 unknown[883]: fetched user config from "qemu" Oct 28 05:15:15.715797 ignition[883]: fetch-offline: fetch-offline passed Oct 28 05:15:15.719268 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Oct 28 05:15:15.715875 ignition[883]: Ignition finished successfully Oct 28 05:15:15.720958 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Oct 28 05:15:15.721975 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Oct 28 05:15:15.759806 ignition[893]: Ignition 2.22.0 Oct 28 05:15:15.759820 ignition[893]: Stage: kargs Oct 28 05:15:15.759989 ignition[893]: no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:15.760000 ignition[893]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:15.760670 ignition[893]: kargs: kargs passed Oct 28 05:15:15.760714 ignition[893]: Ignition finished successfully Oct 28 05:15:15.766901 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Oct 28 05:15:15.768974 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Oct 28 05:15:15.802736 ignition[901]: Ignition 2.22.0 Oct 28 05:15:15.802751 ignition[901]: Stage: disks Oct 28 05:15:15.802885 ignition[901]: no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:15.802896 ignition[901]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:15.803484 ignition[901]: disks: disks passed Oct 28 05:15:15.803531 ignition[901]: Ignition finished successfully Oct 28 05:15:15.822312 systemd[1]: Finished ignition-disks.service - Ignition (disks). Oct 28 05:15:15.825483 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Oct 28 05:15:15.828998 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Oct 28 05:15:15.829901 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 28 05:15:15.833354 systemd[1]: Reached target sysinit.target - System Initialization. Oct 28 05:15:15.836378 systemd[1]: Reached target basic.target - Basic System. Oct 28 05:15:15.840770 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Oct 28 05:15:15.884929 systemd-fsck[911]: ROOT: clean, 15/456736 files, 38230/456704 blocks Oct 28 05:15:16.227373 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Oct 28 05:15:16.231620 systemd[1]: Mounting sysroot.mount - /sysroot... Oct 28 05:15:16.372459 kernel: EXT4-fs (vda9): mounted filesystem 0ce42fa0-8451-4928-b788-6e54ab295d7a r/w with ordered data mode. Quota mode: none. Oct 28 05:15:16.373360 systemd[1]: Mounted sysroot.mount - /sysroot. Oct 28 05:15:16.374844 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Oct 28 05:15:16.379319 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 28 05:15:16.382045 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Oct 28 05:15:16.384522 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Oct 28 05:15:16.448554 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (920) Oct 28 05:15:16.448591 kernel: BTRFS info (device vda6): first mount of filesystem 7acd037c-32ce-4796-90d6-101869832417 Oct 28 05:15:16.384571 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Oct 28 05:15:16.458361 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 28 05:15:16.458385 kernel: BTRFS info (device vda6): turning on async discard Oct 28 05:15:16.458397 kernel: BTRFS info (device vda6): enabling free space tree Oct 28 05:15:16.384602 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Oct 28 05:15:16.446629 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Oct 28 05:15:16.446708 systemd-networkd[712]: eth0: Gained IPv6LL Oct 28 05:15:16.452746 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Oct 28 05:15:16.461739 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 28 05:15:16.514065 initrd-setup-root[944]: cut: /sysroot/etc/passwd: No such file or directory Oct 28 05:15:16.520510 initrd-setup-root[951]: cut: /sysroot/etc/group: No such file or directory Oct 28 05:15:16.525253 initrd-setup-root[958]: cut: /sysroot/etc/shadow: No such file or directory Oct 28 05:15:16.531212 initrd-setup-root[965]: cut: /sysroot/etc/gshadow: No such file or directory Oct 28 05:15:16.637862 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Oct 28 05:15:16.641573 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Oct 28 05:15:16.643018 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Oct 28 05:15:16.666882 systemd[1]: sysroot-oem.mount: Deactivated successfully. Oct 28 05:15:16.669243 kernel: BTRFS info (device vda6): last unmount of filesystem 7acd037c-32ce-4796-90d6-101869832417 Oct 28 05:15:16.684351 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Oct 28 05:15:16.706125 ignition[1034]: INFO : Ignition 2.22.0 Oct 28 05:15:16.706125 ignition[1034]: INFO : Stage: mount Oct 28 05:15:16.708908 ignition[1034]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:16.708908 ignition[1034]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:16.708908 ignition[1034]: INFO : mount: mount passed Oct 28 05:15:16.708908 ignition[1034]: INFO : Ignition finished successfully Oct 28 05:15:16.710333 systemd[1]: Finished ignition-mount.service - Ignition (mount). Oct 28 05:15:16.713357 systemd[1]: Starting ignition-files.service - Ignition (files)... Oct 28 05:15:16.744838 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 28 05:15:16.777963 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (1046) Oct 28 05:15:16.778013 kernel: BTRFS info (device vda6): first mount of filesystem 7acd037c-32ce-4796-90d6-101869832417 Oct 28 05:15:16.778027 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 28 05:15:16.783211 kernel: BTRFS info (device vda6): turning on async discard Oct 28 05:15:16.783242 kernel: BTRFS info (device vda6): enabling free space tree Oct 28 05:15:16.785701 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 28 05:15:16.823227 ignition[1063]: INFO : Ignition 2.22.0 Oct 28 05:15:16.823227 ignition[1063]: INFO : Stage: files Oct 28 05:15:16.826241 ignition[1063]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:16.826241 ignition[1063]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:16.826241 ignition[1063]: DEBUG : files: compiled without relabeling support, skipping Oct 28 05:15:16.826241 ignition[1063]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Oct 28 05:15:16.826241 ignition[1063]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/etc/flatcar/update.conf" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/etc/flatcar/update.conf" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: op(4): [started] processing unit "etcd-member.service" Oct 28 05:15:16.836941 ignition[1063]: INFO : files: op(4): op(5): [started] writing systemd drop-in "20-clct-etcd-member.conf" at "/sysroot/etc/systemd/system/etcd-member.service.d/20-clct-etcd-member.conf" Oct 28 05:15:16.829726 unknown[1063]: wrote ssh authorized keys file for user: core Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(4): op(5): [finished] writing systemd drop-in "20-clct-etcd-member.conf" at "/sysroot/etc/systemd/system/etcd-member.service.d/20-clct-etcd-member.conf" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(4): [finished] processing unit "etcd-member.service" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(6): [started] processing unit "coreos-metadata.service" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(6): op(7): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(6): op(7): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(6): [finished] processing unit "coreos-metadata.service" Oct 28 05:15:16.859060 ignition[1063]: INFO : files: op(8): [started] setting preset to disabled for "coreos-metadata.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: op(8): op(9): [started] removing enablement symlink(s) for "coreos-metadata.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: op(8): op(9): [finished] removing enablement symlink(s) for "coreos-metadata.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: op(8): [finished] setting preset to disabled for "coreos-metadata.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: op(a): [started] setting preset to enabled for "etcd-member.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: op(a): [finished] setting preset to enabled for "etcd-member.service" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Oct 28 05:15:16.883075 ignition[1063]: INFO : files: files passed Oct 28 05:15:16.883075 ignition[1063]: INFO : Ignition finished successfully Oct 28 05:15:16.873001 systemd[1]: Finished ignition-files.service - Ignition (files). Oct 28 05:15:16.876919 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Oct 28 05:15:16.879747 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Oct 28 05:15:16.892476 systemd[1]: ignition-quench.service: Deactivated successfully. Oct 28 05:15:16.913033 initrd-setup-root-after-ignition[1093]: grep: /sysroot/oem/oem-release: No such file or directory Oct 28 05:15:16.892611 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Oct 28 05:15:16.916956 initrd-setup-root-after-ignition[1095]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 28 05:15:16.916956 initrd-setup-root-after-ignition[1095]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Oct 28 05:15:16.921901 initrd-setup-root-after-ignition[1100]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 28 05:15:16.925650 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 28 05:15:16.926477 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Oct 28 05:15:16.932069 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Oct 28 05:15:17.004250 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Oct 28 05:15:17.004443 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Oct 28 05:15:17.005573 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Oct 28 05:15:17.010252 systemd[1]: Reached target initrd.target - Initrd Default Target. Oct 28 05:15:17.015764 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Oct 28 05:15:17.017033 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Oct 28 05:15:17.037637 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 28 05:15:17.040073 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Oct 28 05:15:17.066750 systemd[1]: Unnecessary job was removed for dev-mapper-usr.device - /dev/mapper/usr. Oct 28 05:15:17.066915 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Oct 28 05:15:17.070683 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 28 05:15:17.071875 systemd[1]: Stopped target timers.target - Timer Units. Oct 28 05:15:17.076845 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Oct 28 05:15:17.076998 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 28 05:15:17.082183 systemd[1]: Stopped target initrd.target - Initrd Default Target. Oct 28 05:15:17.085499 systemd[1]: Stopped target basic.target - Basic System. Oct 28 05:15:17.086384 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Oct 28 05:15:17.090323 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Oct 28 05:15:17.093953 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Oct 28 05:15:17.097267 systemd[1]: Stopped target initrd-usr-fs.target - Initrd /usr File System. Oct 28 05:15:17.100975 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Oct 28 05:15:17.104104 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Oct 28 05:15:17.107253 systemd[1]: Stopped target sysinit.target - System Initialization. Oct 28 05:15:17.111053 systemd[1]: Stopped target local-fs.target - Local File Systems. Oct 28 05:15:17.114233 systemd[1]: Stopped target swap.target - Swaps. Oct 28 05:15:17.117932 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Oct 28 05:15:17.118052 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Oct 28 05:15:17.122323 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Oct 28 05:15:17.123257 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 28 05:15:17.128037 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Oct 28 05:15:17.130795 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 28 05:15:17.131958 systemd[1]: dracut-initqueue.service: Deactivated successfully. Oct 28 05:15:17.132086 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Oct 28 05:15:17.139459 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Oct 28 05:15:17.139582 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Oct 28 05:15:17.140406 systemd[1]: Stopped target paths.target - Path Units. Oct 28 05:15:17.144908 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Oct 28 05:15:17.150530 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 28 05:15:17.151348 systemd[1]: Stopped target slices.target - Slice Units. Oct 28 05:15:17.155505 systemd[1]: Stopped target sockets.target - Socket Units. Oct 28 05:15:17.158262 systemd[1]: iscsid.socket: Deactivated successfully. Oct 28 05:15:17.158385 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Oct 28 05:15:17.161072 systemd[1]: iscsiuio.socket: Deactivated successfully. Oct 28 05:15:17.161157 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 28 05:15:17.164121 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Oct 28 05:15:17.164247 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 28 05:15:17.167098 systemd[1]: ignition-files.service: Deactivated successfully. Oct 28 05:15:17.167216 systemd[1]: Stopped ignition-files.service - Ignition (files). Oct 28 05:15:17.174357 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Oct 28 05:15:17.175832 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Oct 28 05:15:17.181829 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Oct 28 05:15:17.182033 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 28 05:15:17.183048 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Oct 28 05:15:17.183174 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Oct 28 05:15:17.187416 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Oct 28 05:15:17.187555 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Oct 28 05:15:17.206682 systemd[1]: initrd-cleanup.service: Deactivated successfully. Oct 28 05:15:17.207533 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Oct 28 05:15:17.215239 ignition[1121]: INFO : Ignition 2.22.0 Oct 28 05:15:17.215239 ignition[1121]: INFO : Stage: umount Oct 28 05:15:17.217735 ignition[1121]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 28 05:15:17.217735 ignition[1121]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 28 05:15:17.217735 ignition[1121]: INFO : umount: umount passed Oct 28 05:15:17.217735 ignition[1121]: INFO : Ignition finished successfully Oct 28 05:15:17.223268 systemd[1]: sysroot-boot.mount: Deactivated successfully. Oct 28 05:15:17.223909 systemd[1]: ignition-mount.service: Deactivated successfully. Oct 28 05:15:17.224039 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Oct 28 05:15:17.228249 systemd[1]: sysroot-boot.service: Deactivated successfully. Oct 28 05:15:17.228391 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Oct 28 05:15:17.231365 systemd[1]: Stopped target network.target - Network. Oct 28 05:15:17.232881 systemd[1]: ignition-disks.service: Deactivated successfully. Oct 28 05:15:17.232965 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Oct 28 05:15:17.233466 systemd[1]: ignition-kargs.service: Deactivated successfully. Oct 28 05:15:17.233515 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Oct 28 05:15:17.238453 systemd[1]: ignition-setup.service: Deactivated successfully. Oct 28 05:15:17.238513 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Oct 28 05:15:17.241257 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Oct 28 05:15:17.241309 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Oct 28 05:15:17.244226 systemd[1]: initrd-setup-root.service: Deactivated successfully. Oct 28 05:15:17.244283 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Oct 28 05:15:17.247487 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Oct 28 05:15:17.253179 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Oct 28 05:15:17.263149 systemd[1]: systemd-networkd.service: Deactivated successfully. Oct 28 05:15:17.263300 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Oct 28 05:15:17.273443 systemd[1]: systemd-resolved.service: Deactivated successfully. Oct 28 05:15:17.273657 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Oct 28 05:15:17.279392 systemd[1]: Stopped target network-pre.target - Preparation for Network. Oct 28 05:15:17.282829 systemd[1]: systemd-networkd.socket: Deactivated successfully. Oct 28 05:15:17.282886 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Oct 28 05:15:17.288117 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Oct 28 05:15:17.288778 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Oct 28 05:15:17.288842 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 28 05:15:17.289449 systemd[1]: systemd-sysctl.service: Deactivated successfully. Oct 28 05:15:17.289497 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Oct 28 05:15:17.296224 systemd[1]: systemd-modules-load.service: Deactivated successfully. Oct 28 05:15:17.296277 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Oct 28 05:15:17.300100 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 28 05:15:17.316280 systemd[1]: systemd-udevd.service: Deactivated successfully. Oct 28 05:15:17.316516 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 28 05:15:17.317576 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Oct 28 05:15:17.317627 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Oct 28 05:15:17.322477 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Oct 28 05:15:17.322523 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Oct 28 05:15:17.325969 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Oct 28 05:15:17.326027 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Oct 28 05:15:17.331614 systemd[1]: dracut-cmdline.service: Deactivated successfully. Oct 28 05:15:17.331674 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Oct 28 05:15:17.336014 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Oct 28 05:15:17.336080 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 28 05:15:17.340528 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Oct 28 05:15:17.341976 systemd[1]: systemd-network-generator.service: Deactivated successfully. Oct 28 05:15:17.342040 systemd[1]: Stopped systemd-network-generator.service - Generate network units from Kernel command line. Oct 28 05:15:17.345342 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Oct 28 05:15:17.345398 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 28 05:15:17.348942 systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. Oct 28 05:15:17.348996 systemd[1]: Stopped systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 28 05:15:17.349873 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Oct 28 05:15:17.349924 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Oct 28 05:15:17.358254 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 28 05:15:17.358313 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:17.378740 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Oct 28 05:15:17.378890 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Oct 28 05:15:17.407254 systemd[1]: network-cleanup.service: Deactivated successfully. Oct 28 05:15:17.407440 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Oct 28 05:15:17.408505 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Oct 28 05:15:17.415143 systemd[1]: Starting initrd-switch-root.service - Switch Root... Oct 28 05:15:17.439530 systemd[1]: Switching root. Oct 28 05:15:17.475035 systemd-journald[311]: Journal stopped Oct 28 05:15:18.499241 systemd-journald[311]: Received SIGTERM from PID 1 (systemd). Oct 28 05:15:18.499322 kernel: SELinux: policy capability network_peer_controls=1 Oct 28 05:15:18.499338 kernel: SELinux: policy capability open_perms=1 Oct 28 05:15:18.499382 kernel: SELinux: policy capability extended_socket_class=1 Oct 28 05:15:18.499395 kernel: SELinux: policy capability always_check_network=0 Oct 28 05:15:18.499407 kernel: SELinux: policy capability cgroup_seclabel=1 Oct 28 05:15:18.499475 kernel: SELinux: policy capability nnp_nosuid_transition=1 Oct 28 05:15:18.499489 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Oct 28 05:15:18.499501 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Oct 28 05:15:18.499513 kernel: SELinux: policy capability userspace_initial_context=0 Oct 28 05:15:18.499535 kernel: audit: type=1403 audit(1761628517.567:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Oct 28 05:15:18.499549 systemd[1]: Successfully loaded SELinux policy in 69.129ms. Oct 28 05:15:18.499577 systemd[1]: Relabeled /dev/, /dev/shm/, /run/ in 11.788ms. Oct 28 05:15:18.499590 systemd[1]: systemd 257.7 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +IPE +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 -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) Oct 28 05:15:18.499606 systemd[1]: Detected virtualization kvm. Oct 28 05:15:18.499619 systemd[1]: Detected architecture x86-64. Oct 28 05:15:18.499632 systemd[1]: Detected first boot. Oct 28 05:15:18.499654 systemd[1]: Initializing machine ID from SMBIOS/DMI UUID. Oct 28 05:15:18.499668 zram_generator::config[1188]: No configuration found. Oct 28 05:15:18.499683 kernel: Guest personality initialized and is inactive Oct 28 05:15:18.499699 kernel: VMCI host device registered (name=vmci, major=10, minor=125) Oct 28 05:15:18.499711 kernel: Initialized host personality Oct 28 05:15:18.499724 kernel: NET: Registered PF_VSOCK protocol family Oct 28 05:15:18.499737 systemd[1]: Populated /etc with preset unit settings. Oct 28 05:15:18.499757 systemd[1]: initrd-switch-root.service: Deactivated successfully. Oct 28 05:15:18.499769 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Oct 28 05:15:18.499782 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Oct 28 05:15:18.499797 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Oct 28 05:15:18.499810 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Oct 28 05:15:18.499823 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Oct 28 05:15:18.499847 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Oct 28 05:15:18.499875 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Oct 28 05:15:18.499889 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Oct 28 05:15:18.499902 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Oct 28 05:15:18.499915 systemd[1]: Created slice user.slice - User and Session Slice. Oct 28 05:15:18.499935 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 28 05:15:18.499948 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 28 05:15:18.499961 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Oct 28 05:15:18.499974 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Oct 28 05:15:18.499987 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Oct 28 05:15:18.500001 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 28 05:15:18.500030 systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0... Oct 28 05:15:18.500044 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 28 05:15:18.500057 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 28 05:15:18.500071 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Oct 28 05:15:18.500083 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Oct 28 05:15:18.500096 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Oct 28 05:15:18.500109 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Oct 28 05:15:18.500130 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 28 05:15:18.500144 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 28 05:15:18.500157 systemd[1]: Reached target slices.target - Slice Units. Oct 28 05:15:18.500170 systemd[1]: Reached target swap.target - Swaps. Oct 28 05:15:18.500183 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Oct 28 05:15:18.500196 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Oct 28 05:15:18.500210 systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. Oct 28 05:15:18.500231 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 28 05:15:18.500244 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 28 05:15:18.500258 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 28 05:15:18.500270 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Oct 28 05:15:18.500284 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Oct 28 05:15:18.500297 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Oct 28 05:15:18.500310 systemd[1]: Mounting media.mount - External Media Directory... Oct 28 05:15:18.500331 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 28 05:15:18.500344 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Oct 28 05:15:18.500358 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Oct 28 05:15:18.500371 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Oct 28 05:15:18.500385 systemd[1]: var-lib-machines.mount - Virtual Machine and Container Storage (Compatibility) was skipped because of an unmet condition check (ConditionPathExists=/var/lib/machines.raw). Oct 28 05:15:18.500398 systemd[1]: Reached target machines.target - Containers. Oct 28 05:15:18.500410 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Oct 28 05:15:18.500444 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 28 05:15:18.500458 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 28 05:15:18.500471 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Oct 28 05:15:18.500483 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 28 05:15:18.500496 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 28 05:15:18.500509 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 28 05:15:18.500522 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Oct 28 05:15:18.500543 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 28 05:15:18.500556 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Oct 28 05:15:18.500573 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Oct 28 05:15:18.500590 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Oct 28 05:15:18.500608 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Oct 28 05:15:18.500626 systemd[1]: Stopped systemd-fsck-usr.service. Oct 28 05:15:18.500653 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). Oct 28 05:15:18.500667 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 28 05:15:18.500680 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 28 05:15:18.500693 kernel: fuse: init (API version 7.41) Oct 28 05:15:18.500705 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Oct 28 05:15:18.500718 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Oct 28 05:15:18.500731 systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... Oct 28 05:15:18.500753 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 28 05:15:18.500767 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 28 05:15:18.500780 kernel: ACPI: bus type drm_connector registered Oct 28 05:15:18.500793 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Oct 28 05:15:18.500813 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Oct 28 05:15:18.500826 systemd[1]: Mounted media.mount - External Media Directory. Oct 28 05:15:18.500839 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Oct 28 05:15:18.500852 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Oct 28 05:15:18.500865 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Oct 28 05:15:18.500898 systemd-journald[1270]: Collecting audit messages is disabled. Oct 28 05:15:18.500931 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Oct 28 05:15:18.500945 systemd-journald[1270]: Journal started Oct 28 05:15:18.500967 systemd-journald[1270]: Runtime Journal (/run/log/journal/c48b096d43c04bbe86df3af6f6588e0f) is 6M, max 48.1M, 42.1M free. Oct 28 05:15:18.151128 systemd[1]: Queued start job for default target multi-user.target. Oct 28 05:15:18.170525 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Oct 28 05:15:18.171084 systemd[1]: systemd-journald.service: Deactivated successfully. Oct 28 05:15:18.504511 systemd[1]: Started systemd-journald.service - Journal Service. Oct 28 05:15:18.506971 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 28 05:15:18.509385 systemd[1]: modprobe@configfs.service: Deactivated successfully. Oct 28 05:15:18.509626 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Oct 28 05:15:18.511993 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 28 05:15:18.512219 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 28 05:15:18.514547 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 28 05:15:18.514775 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 28 05:15:18.517035 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 28 05:15:18.517253 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 28 05:15:18.519694 systemd[1]: modprobe@fuse.service: Deactivated successfully. Oct 28 05:15:18.519922 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Oct 28 05:15:18.521998 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 28 05:15:18.522234 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 28 05:15:18.524330 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 28 05:15:18.526660 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Oct 28 05:15:18.529876 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Oct 28 05:15:18.532333 systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. Oct 28 05:15:18.551890 systemd[1]: Reached target network-pre.target - Preparation for Network. Oct 28 05:15:18.554522 systemd[1]: Listening on systemd-importd.socket - Disk Image Download Service Socket. Oct 28 05:15:18.558219 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Oct 28 05:15:18.561392 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Oct 28 05:15:18.563623 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Oct 28 05:15:18.563660 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 28 05:15:18.565397 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. Oct 28 05:15:18.568004 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 28 05:15:18.578396 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Oct 28 05:15:18.582070 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Oct 28 05:15:18.584255 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 28 05:15:18.586125 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Oct 28 05:15:18.588468 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 28 05:15:18.593173 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 28 05:15:18.600656 systemd-journald[1270]: Time spent on flushing to /var/log/journal/c48b096d43c04bbe86df3af6f6588e0f is 34.431ms for 1031 entries. Oct 28 05:15:18.600656 systemd-journald[1270]: System Journal (/var/log/journal/c48b096d43c04bbe86df3af6f6588e0f) is 8M, max 163.5M, 155.5M free. Oct 28 05:15:18.650147 systemd-journald[1270]: Received client request to flush runtime journal. Oct 28 05:15:18.603285 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Oct 28 05:15:18.608607 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 28 05:15:18.616791 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 28 05:15:18.621960 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Oct 28 05:15:18.625247 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Oct 28 05:15:19.677470 kernel: clocksource: Long readout interval, skipping watchdog check: cs_nsec: 1387589811 wd_nsec: 1387589225 Oct 28 05:15:19.679773 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Oct 28 05:15:19.685308 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Oct 28 05:15:19.697476 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 28 05:15:19.702452 kernel: loop1: detected capacity change from 0 to 111544 Oct 28 05:15:19.702533 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Oct 28 05:15:19.706619 systemd[1]: Starting systemd-machine-id-commit.service - Save Transient machine-id to Disk... Oct 28 05:15:19.712342 systemd-tmpfiles[1308]: ACLs are not supported, ignoring. Oct 28 05:15:19.712366 systemd-tmpfiles[1308]: ACLs are not supported, ignoring. Oct 28 05:15:19.719860 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 28 05:15:19.725054 systemd[1]: Starting systemd-sysusers.service - Create System Users... Oct 28 05:15:19.743441 kernel: loop2: detected capacity change from 0 to 128912 Oct 28 05:15:19.746306 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Oct 28 05:15:19.747971 systemd[1]: Finished systemd-machine-id-commit.service - Save Transient machine-id to Disk. Oct 28 05:15:19.770614 systemd[1]: Finished systemd-sysusers.service - Create System Users. Oct 28 05:15:19.775088 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 28 05:15:19.779559 kernel: loop3: detected capacity change from 0 to 111544 Oct 28 05:15:19.782721 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 28 05:15:19.856825 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Oct 28 05:15:19.857470 kernel: loop4: detected capacity change from 0 to 128912 Oct 28 05:15:19.869390 (sd-merge)[1329]: Using extensions 'containerd-flatcar.raw', 'docker-flatcar.raw'. Oct 28 05:15:19.875229 (sd-merge)[1329]: Merged extensions into '/usr'. Oct 28 05:15:19.881046 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Oct 28 05:15:19.886001 systemd[1]: Starting ensure-sysext.service... Oct 28 05:15:19.892558 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 28 05:15:19.898358 systemd-tmpfiles[1330]: ACLs are not supported, ignoring. Oct 28 05:15:19.898379 systemd-tmpfiles[1330]: ACLs are not supported, ignoring. Oct 28 05:15:19.903796 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 28 05:15:19.914817 systemd[1]: Reload requested from client PID 1334 ('systemctl') (unit ensure-sysext.service)... Oct 28 05:15:19.914932 systemd[1]: Reloading... Oct 28 05:15:19.923939 systemd-tmpfiles[1335]: /usr/lib/tmpfiles.d/nfs-utils.conf:6: Duplicate line for path "/var/lib/nfs/sm", ignoring. Oct 28 05:15:19.924040 systemd-tmpfiles[1335]: /usr/lib/tmpfiles.d/nfs-utils.conf:7: Duplicate line for path "/var/lib/nfs/sm.bak", ignoring. Oct 28 05:15:19.924447 systemd-tmpfiles[1335]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Oct 28 05:15:19.924872 systemd-tmpfiles[1335]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Oct 28 05:15:19.926305 systemd-tmpfiles[1335]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Oct 28 05:15:19.927147 systemd-tmpfiles[1335]: ACLs are not supported, ignoring. Oct 28 05:15:19.927225 systemd-tmpfiles[1335]: ACLs are not supported, ignoring. Oct 28 05:15:19.937180 systemd-tmpfiles[1335]: Detected autofs mount point /boot during canonicalization of boot. Oct 28 05:15:19.937383 systemd-tmpfiles[1335]: Skipping /boot Oct 28 05:15:19.960671 systemd-tmpfiles[1335]: Detected autofs mount point /boot during canonicalization of boot. Oct 28 05:15:19.960771 systemd-tmpfiles[1335]: Skipping /boot Oct 28 05:15:20.021452 zram_generator::config[1369]: No configuration found. Oct 28 05:15:20.104033 systemd-resolved[1328]: Positive Trust Anchors: Oct 28 05:15:20.104053 systemd-resolved[1328]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 28 05:15:20.104058 systemd-resolved[1328]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b16 Oct 28 05:15:20.104090 systemd-resolved[1328]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 28 05:15:20.108380 systemd-resolved[1328]: Defaulting to hostname 'linux'. Oct 28 05:15:20.240748 systemd[1]: Reloading finished in 325 ms. Oct 28 05:15:20.288997 systemd[1]: Started systemd-userdbd.service - User Database Manager. Oct 28 05:15:20.291467 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 28 05:15:20.330673 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 28 05:15:20.338675 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 28 05:15:20.342344 systemd[1]: Starting audit-rules.service - Load Audit Rules... Oct 28 05:15:20.345314 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Oct 28 05:15:20.408563 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Oct 28 05:15:20.411995 augenrules[1431]: No rules Oct 28 05:15:20.413712 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Oct 28 05:15:20.417693 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Oct 28 05:15:20.422776 systemd[1]: audit-rules.service: Deactivated successfully. Oct 28 05:15:20.423144 systemd[1]: Finished audit-rules.service - Load Audit Rules. Oct 28 05:15:20.429239 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 28 05:15:20.431895 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 28 05:15:20.437032 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 28 05:15:20.442821 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 28 05:15:20.444596 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 28 05:15:20.444719 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). Oct 28 05:15:20.445936 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 28 05:15:20.447490 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 28 05:15:20.456103 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 28 05:15:20.462315 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 28 05:15:20.464359 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 28 05:15:20.464548 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). Oct 28 05:15:20.465905 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Oct 28 05:15:20.471349 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Oct 28 05:15:20.474201 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 28 05:15:20.474491 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 28 05:15:20.477333 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Oct 28 05:15:20.479948 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 28 05:15:20.480180 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 28 05:15:20.494219 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 28 05:15:20.494986 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 28 05:15:20.504412 systemd[1]: Starting audit-rules.service - Load Audit Rules... Oct 28 05:15:20.506122 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 28 05:15:20.507464 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 28 05:15:20.512647 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 28 05:15:20.517498 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 28 05:15:20.520609 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 28 05:15:20.523712 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 28 05:15:20.523766 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). Oct 28 05:15:20.523849 systemd[1]: update-ca-certificates.service - Update CA bundle at /etc/ssl/certs/ca-certificates.crt was skipped because of an unmet condition check (ConditionPathIsSymbolicLink=!/etc/ssl/certs/ca-certificates.crt). Oct 28 05:15:20.524804 systemd[1]: Finished ensure-sysext.service. Oct 28 05:15:20.526638 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 28 05:15:20.526887 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 28 05:15:20.530195 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 28 05:15:20.530416 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 28 05:15:20.540830 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Oct 28 05:15:20.543770 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 28 05:15:20.544069 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 28 05:15:20.546631 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 28 05:15:20.546841 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 28 05:15:20.551870 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 28 05:15:20.552553 augenrules[1450]: /sbin/augenrules: No change Oct 28 05:15:20.552008 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 28 05:15:20.563122 augenrules[1480]: No rules Oct 28 05:15:20.564206 systemd[1]: audit-rules.service: Deactivated successfully. Oct 28 05:15:20.564551 systemd[1]: Finished audit-rules.service - Load Audit Rules. Oct 28 05:15:20.625622 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Oct 28 05:15:20.630716 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 28 05:15:20.716898 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Oct 28 05:15:20.719446 systemd[1]: Reached target time-set.target - System Time Set. Oct 28 05:15:20.721209 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 28 05:15:20.721234 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 28 05:15:20.751322 systemd-udevd[1487]: Using default interface naming scheme 'v257'. Oct 28 05:15:20.777269 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 28 05:15:20.786198 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 28 05:15:20.856059 systemd[1]: Condition check resulted in dev-ttyS0.device - /dev/ttyS0 being skipped. Oct 28 05:15:20.894381 systemd-networkd[1498]: lo: Link UP Oct 28 05:15:20.894393 systemd-networkd[1498]: lo: Gained carrier Oct 28 05:15:20.895731 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 28 05:15:20.897684 systemd[1]: Reached target network.target - Network. Oct 28 05:15:20.901756 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... Oct 28 05:15:20.906542 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Oct 28 05:15:20.946937 systemd-networkd[1498]: eth0: Found matching .network file, based on potentially unpredictable interface name: /usr/lib/systemd/network/zz-default.network Oct 28 05:15:20.946955 systemd-networkd[1498]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 28 05:15:20.950035 systemd-networkd[1498]: eth0: Link UP Oct 28 05:15:20.952717 systemd-networkd[1498]: eth0: Gained carrier Oct 28 05:15:20.952736 systemd-networkd[1498]: eth0: Found matching .network file, based on potentially unpredictable interface name: /usr/lib/systemd/network/zz-default.network Oct 28 05:15:20.954486 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. Oct 28 05:15:21.004721 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input4 Oct 28 05:15:21.010463 kernel: ACPI: button: Power Button [PWRF] Oct 28 05:15:21.013549 systemd-networkd[1498]: eth0: DHCPv4 address 10.0.0.72/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 28 05:15:21.015293 systemd-timesyncd[1465]: Network configuration changed, trying to establish connection. Oct 28 05:15:21.965333 systemd-timesyncd[1465]: Contacted time server 10.0.0.1:123 (10.0.0.1). Oct 28 05:15:21.965398 systemd-timesyncd[1465]: Initial clock synchronization to Tue 2025-10-28 05:15:21.965213 UTC. Oct 28 05:15:21.966021 systemd-resolved[1328]: Clock change detected. Flushing caches. Oct 28 05:15:21.968482 kernel: mousedev: PS/2 mouse device common for all mice Oct 28 05:15:21.976244 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 28 05:15:21.981431 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Oct 28 05:15:22.013012 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Oct 28 05:15:22.075995 kernel: i801_smbus 0000:00:1f.3: Enabling SMBus device Oct 28 05:15:22.076701 kernel: i801_smbus 0000:00:1f.3: SMBus using PCI interrupt Oct 28 05:15:22.077001 kernel: i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD Oct 28 05:15:22.132370 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 28 05:15:22.233932 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 28 05:15:22.234550 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:22.241738 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 28 05:15:22.267802 ldconfig[1411]: /sbin/ldconfig: /usr/lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Oct 28 05:15:22.273315 kernel: kvm_amd: TSC scaling supported Oct 28 05:15:22.273371 kernel: kvm_amd: Nested Virtualization enabled Oct 28 05:15:22.273386 kernel: kvm_amd: Nested Paging enabled Oct 28 05:15:22.273399 kernel: kvm_amd: LBR virtualization supported Oct 28 05:15:22.274319 kernel: kvm_amd: Virtual VMLOAD VMSAVE supported Oct 28 05:15:22.275237 kernel: kvm_amd: Virtual GIF supported Oct 28 05:15:22.276032 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Oct 28 05:15:22.281041 systemd[1]: Starting systemd-update-done.service - Update is Completed... Oct 28 05:15:22.304175 systemd[1]: Finished systemd-update-done.service - Update is Completed. Oct 28 05:15:22.307505 kernel: EDAC MC: Ver: 3.0.0 Oct 28 05:15:22.343129 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 28 05:15:22.346701 systemd[1]: Reached target sysinit.target - System Initialization. Oct 28 05:15:22.348506 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Oct 28 05:15:22.350532 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Oct 28 05:15:22.352517 systemd[1]: Started google-oslogin-cache.timer - NSS cache refresh timer. Oct 28 05:15:22.354499 systemd[1]: Started logrotate.timer - Daily rotation of log files. Oct 28 05:15:22.356493 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Oct 28 05:15:22.358533 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Oct 28 05:15:22.360522 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Oct 28 05:15:22.360576 systemd[1]: Reached target paths.target - Path Units. Oct 28 05:15:22.362025 systemd[1]: Reached target timers.target - Timer Units. Oct 28 05:15:22.364280 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Oct 28 05:15:22.368078 systemd[1]: Starting docker.socket - Docker Socket for the API... Oct 28 05:15:22.371879 systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). Oct 28 05:15:22.374192 systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). Oct 28 05:15:22.376339 systemd[1]: Reached target ssh-access.target - SSH Access Available. Oct 28 05:15:22.383146 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Oct 28 05:15:22.387963 systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. Oct 28 05:15:22.390514 systemd[1]: Listening on docker.socket - Docker Socket for the API. Oct 28 05:15:22.392921 systemd[1]: Reached target sockets.target - Socket Units. Oct 28 05:15:22.394451 systemd[1]: Reached target basic.target - Basic System. Oct 28 05:15:22.395958 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Oct 28 05:15:22.395999 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Oct 28 05:15:22.397096 systemd[1]: Starting containerd.service - containerd container runtime... Oct 28 05:15:22.399781 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Oct 28 05:15:22.403606 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Oct 28 05:15:22.407026 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Oct 28 05:15:22.419880 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Oct 28 05:15:22.421604 systemd[1]: flatcar-setup-environment.service - Modifies /etc/environment for CoreOS was skipped because of an unmet condition check (ConditionPathExists=/oem/bin/flatcar-setup-environment). Oct 28 05:15:22.422205 jq[1561]: false Oct 28 05:15:22.422842 systemd[1]: Starting google-oslogin-cache.service - NSS cache refresh... Oct 28 05:15:22.425759 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Oct 28 05:15:22.428553 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Oct 28 05:15:22.434833 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Refreshing passwd entry cache Oct 28 05:15:22.433890 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Oct 28 05:15:22.433612 oslogin_cache_refresh[1563]: Refreshing passwd entry cache Oct 28 05:15:22.440867 systemd[1]: Starting systemd-logind.service - User Login Management... Oct 28 05:15:22.442629 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Oct 28 05:15:22.442795 oslogin_cache_refresh[1563]: Failure getting users, quitting Oct 28 05:15:22.443045 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Failure getting users, quitting Oct 28 05:15:22.443045 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Produced empty passwd cache file, removing /etc/oslogin_passwd.cache.bak. Oct 28 05:15:22.443045 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Refreshing group entry cache Oct 28 05:15:22.442816 oslogin_cache_refresh[1563]: Produced empty passwd cache file, removing /etc/oslogin_passwd.cache.bak. Oct 28 05:15:22.442876 oslogin_cache_refresh[1563]: Refreshing group entry cache Oct 28 05:15:22.444178 extend-filesystems[1562]: Found /dev/vda6 Oct 28 05:15:22.445851 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Oct 28 05:15:22.446726 systemd[1]: Starting update-engine.service - Update Engine... Oct 28 05:15:22.449507 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Failure getting groups, quitting Oct 28 05:15:22.449507 google_oslogin_nss_cache[1563]: oslogin_cache_refresh[1563]: Produced empty group cache file, removing /etc/oslogin_group.cache.bak. Oct 28 05:15:22.449482 oslogin_cache_refresh[1563]: Failure getting groups, quitting Oct 28 05:15:22.449494 oslogin_cache_refresh[1563]: Produced empty group cache file, removing /etc/oslogin_group.cache.bak. Oct 28 05:15:22.449960 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Oct 28 05:15:22.454418 extend-filesystems[1562]: Found /dev/vda9 Oct 28 05:15:22.457919 extend-filesystems[1562]: Checking size of /dev/vda9 Oct 28 05:15:22.456714 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Oct 28 05:15:22.465083 jq[1578]: true Oct 28 05:15:22.459031 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Oct 28 05:15:22.459319 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Oct 28 05:15:22.460275 systemd[1]: google-oslogin-cache.service: Deactivated successfully. Oct 28 05:15:22.460722 systemd[1]: Finished google-oslogin-cache.service - NSS cache refresh. Oct 28 05:15:22.466262 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Oct 28 05:15:22.469727 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Oct 28 05:15:22.472901 systemd[1]: motdgen.service: Deactivated successfully. Oct 28 05:15:22.473201 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Oct 28 05:15:22.477064 update_engine[1577]: I20251028 05:15:22.476907 1577 main.cc:92] Flatcar Update Engine starting Oct 28 05:15:22.479128 extend-filesystems[1562]: Resized partition /dev/vda9 Oct 28 05:15:22.483122 extend-filesystems[1599]: resize2fs 1.47.3 (8-Jul-2025) Oct 28 05:15:22.488554 kernel: EXT4-fs (vda9): resizing filesystem from 456704 to 474107 blocks Oct 28 05:15:22.492513 kernel: EXT4-fs (vda9): resized filesystem to 474107 Oct 28 05:15:22.508173 jq[1593]: true Oct 28 05:15:22.508442 extend-filesystems[1599]: Filesystem at /dev/vda9 is mounted on /; on-line resizing required Oct 28 05:15:22.508442 extend-filesystems[1599]: old_desc_blocks = 1, new_desc_blocks = 1 Oct 28 05:15:22.508442 extend-filesystems[1599]: The filesystem on /dev/vda9 is now 474107 (4k) blocks long. Oct 28 05:15:22.515582 systemd[1]: extend-filesystems.service: Deactivated successfully. Oct 28 05:15:22.517194 extend-filesystems[1562]: Resized filesystem in /dev/vda9 Oct 28 05:15:22.517563 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Oct 28 05:15:22.595896 systemd-logind[1570]: Watching system buttons on /dev/input/event2 (Power Button) Oct 28 05:15:22.595923 systemd-logind[1570]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) Oct 28 05:15:22.596395 systemd-logind[1570]: New seat seat0. Oct 28 05:15:22.598008 dbus-daemon[1559]: [system] SELinux support is enabled Oct 28 05:15:22.598351 systemd[1]: Started dbus.service - D-Bus System Message Bus. Oct 28 05:15:22.604208 systemd[1]: Started systemd-logind.service - User Login Management. Oct 28 05:15:22.606358 update_engine[1577]: I20251028 05:15:22.606068 1577 update_check_scheduler.cc:74] Next update check in 2m26s Oct 28 05:15:22.607332 systemd[1]: system-cloudinit@usr-share-oem-cloud\x2dconfig.yml.service - Load cloud-config from /usr/share/oem/cloud-config.yml was skipped because of an unmet condition check (ConditionFileNotEmpty=/usr/share/oem/cloud-config.yml). Oct 28 05:15:22.607362 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Oct 28 05:15:22.609595 systemd[1]: user-cloudinit-proc-cmdline.service - Load cloud-config from url defined in /proc/cmdline was skipped because of an unmet condition check (ConditionKernelCommandLine=cloud-config-url). Oct 28 05:15:22.609624 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Oct 28 05:15:22.614153 systemd[1]: Started update-engine.service - Update Engine. Oct 28 05:15:22.616021 dbus-daemon[1559]: [system] Successfully activated service 'org.freedesktop.systemd1' Oct 28 05:15:22.621168 systemd[1]: Started locksmithd.service - Cluster reboot manager. Oct 28 05:15:22.685893 bash[1624]: Updated "/home/core/.ssh/authorized_keys" Oct 28 05:15:22.686426 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Oct 28 05:15:22.690860 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Oct 28 05:15:22.735703 locksmithd[1625]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Oct 28 05:15:22.741320 sshd_keygen[1591]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Oct 28 05:15:22.830589 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Oct 28 05:15:22.834407 systemd[1]: Starting issuegen.service - Generate /run/issue... Oct 28 05:15:22.862897 systemd[1]: issuegen.service: Deactivated successfully. Oct 28 05:15:22.863209 systemd[1]: Finished issuegen.service - Generate /run/issue. Oct 28 05:15:22.868036 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Oct 28 05:15:22.895720 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Oct 28 05:15:22.899808 systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 28 05:15:22.902761 systemd[1]: Started serial-getty@ttyS0.service - Serial Getty on ttyS0. Oct 28 05:15:22.904768 systemd[1]: Reached target getty.target - Login Prompts. Oct 28 05:15:22.987148 containerd[1595]: time="2025-10-28T05:15:22Z" 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 Oct 28 05:15:22.988901 containerd[1595]: time="2025-10-28T05:15:22.988857226Z" level=info msg="starting containerd" revision=fb4c30d4ede3531652d86197bf3fc9515e5276d9 version=v2.0.5 Oct 28 05:15:23.001007 containerd[1595]: time="2025-10-28T05:15:23.000884972Z" level=warning msg="Configuration migrated from version 2, use `containerd config migrate` to avoid migration" t="22.422µs" Oct 28 05:15:23.001007 containerd[1595]: time="2025-10-28T05:15:23.000928464Z" level=info msg="loading plugin" id=io.containerd.image-verifier.v1.bindir type=io.containerd.image-verifier.v1 Oct 28 05:15:23.001007 containerd[1595]: time="2025-10-28T05:15:23.000970583Z" level=info msg="loading plugin" id=io.containerd.internal.v1.opt type=io.containerd.internal.v1 Oct 28 05:15:23.001603 containerd[1595]: time="2025-10-28T05:15:23.001529000Z" level=info msg="loading plugin" id=io.containerd.warning.v1.deprecations type=io.containerd.warning.v1 Oct 28 05:15:23.001603 containerd[1595]: time="2025-10-28T05:15:23.001590896Z" level=info msg="loading plugin" id=io.containerd.content.v1.content type=io.containerd.content.v1 Oct 28 05:15:23.001750 containerd[1595]: time="2025-10-28T05:15:23.001634308Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 Oct 28 05:15:23.001772 containerd[1595]: time="2025-10-28T05:15:23.001757438Z" level=info msg="skip loading plugin" error="no scratch file generator: skip plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 Oct 28 05:15:23.001792 containerd[1595]: time="2025-10-28T05:15:23.001775813Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.btrfs type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002242 containerd[1595]: time="2025-10-28T05:15:23.002203826Z" 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 Oct 28 05:15:23.002242 containerd[1595]: time="2025-10-28T05:15:23.002225236Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002242 containerd[1595]: time="2025-10-28T05:15:23.002237459Z" level=info msg="skip loading plugin" error="devmapper not configured: skip plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002325 containerd[1595]: time="2025-10-28T05:15:23.002246305Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.native type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002356 containerd[1595]: time="2025-10-28T05:15:23.002339139Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.overlayfs type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002682 containerd[1595]: time="2025-10-28T05:15:23.002646155Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.zfs type=io.containerd.snapshotter.v1 Oct 28 05:15:23.002708 containerd[1595]: time="2025-10-28T05:15:23.002689907Z" 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 Oct 28 05:15:23.002729 containerd[1595]: time="2025-10-28T05:15:23.002708973Z" level=info msg="loading plugin" id=io.containerd.event.v1.exchange type=io.containerd.event.v1 Oct 28 05:15:23.004418 containerd[1595]: time="2025-10-28T05:15:23.004382221Z" level=info msg="loading plugin" id=io.containerd.monitor.task.v1.cgroups type=io.containerd.monitor.task.v1 Oct 28 05:15:23.004726 containerd[1595]: time="2025-10-28T05:15:23.004690389Z" level=info msg="loading plugin" id=io.containerd.metadata.v1.bolt type=io.containerd.metadata.v1 Oct 28 05:15:23.004821 containerd[1595]: time="2025-10-28T05:15:23.004786639Z" level=info msg="metadata content store policy set" policy=shared Oct 28 05:15:23.009898 containerd[1595]: time="2025-10-28T05:15:23.009860635Z" level=info msg="loading plugin" id=io.containerd.gc.v1.scheduler type=io.containerd.gc.v1 Oct 28 05:15:23.009938 containerd[1595]: time="2025-10-28T05:15:23.009917812Z" level=info msg="loading plugin" id=io.containerd.differ.v1.walking type=io.containerd.differ.v1 Oct 28 05:15:23.009938 containerd[1595]: time="2025-10-28T05:15:23.009932490Z" level=info msg="loading plugin" id=io.containerd.lease.v1.manager type=io.containerd.lease.v1 Oct 28 05:15:23.009983 containerd[1595]: time="2025-10-28T05:15:23.009947458Z" level=info msg="loading plugin" id=io.containerd.service.v1.containers-service type=io.containerd.service.v1 Oct 28 05:15:23.009983 containerd[1595]: time="2025-10-28T05:15:23.009971713Z" level=info msg="loading plugin" id=io.containerd.service.v1.content-service type=io.containerd.service.v1 Oct 28 05:15:23.010019 containerd[1595]: time="2025-10-28T05:15:23.009998043Z" level=info msg="loading plugin" id=io.containerd.service.v1.diff-service type=io.containerd.service.v1 Oct 28 05:15:23.010019 containerd[1595]: time="2025-10-28T05:15:23.010015796Z" level=info msg="loading plugin" id=io.containerd.service.v1.images-service type=io.containerd.service.v1 Oct 28 05:15:23.010074 containerd[1595]: time="2025-10-28T05:15:23.010029201Z" level=info msg="loading plugin" id=io.containerd.service.v1.introspection-service type=io.containerd.service.v1 Oct 28 05:15:23.010074 containerd[1595]: time="2025-10-28T05:15:23.010043388Z" level=info msg="loading plugin" id=io.containerd.service.v1.namespaces-service type=io.containerd.service.v1 Oct 28 05:15:23.010074 containerd[1595]: time="2025-10-28T05:15:23.010054569Z" level=info msg="loading plugin" id=io.containerd.service.v1.snapshots-service type=io.containerd.service.v1 Oct 28 05:15:23.010074 containerd[1595]: time="2025-10-28T05:15:23.010065469Z" level=info msg="loading plugin" id=io.containerd.shim.v1.manager type=io.containerd.shim.v1 Oct 28 05:15:23.010143 containerd[1595]: time="2025-10-28T05:15:23.010079105Z" level=info msg="loading plugin" id=io.containerd.runtime.v2.task type=io.containerd.runtime.v2 Oct 28 05:15:23.010240 containerd[1595]: time="2025-10-28T05:15:23.010213136Z" level=info msg="loading plugin" id=io.containerd.service.v1.tasks-service type=io.containerd.service.v1 Oct 28 05:15:23.010273 containerd[1595]: time="2025-10-28T05:15:23.010241449Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.containers type=io.containerd.grpc.v1 Oct 28 05:15:23.010273 containerd[1595]: time="2025-10-28T05:15:23.010256117Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.content type=io.containerd.grpc.v1 Oct 28 05:15:23.010273 containerd[1595]: time="2025-10-28T05:15:23.010269301Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.diff type=io.containerd.grpc.v1 Oct 28 05:15:23.010326 containerd[1595]: time="2025-10-28T05:15:23.010281274Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.events type=io.containerd.grpc.v1 Oct 28 05:15:23.010326 containerd[1595]: time="2025-10-28T05:15:23.010292284Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.images type=io.containerd.grpc.v1 Oct 28 05:15:23.010326 containerd[1595]: time="2025-10-28T05:15:23.010303455Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.introspection type=io.containerd.grpc.v1 Oct 28 05:15:23.010326 containerd[1595]: time="2025-10-28T05:15:23.010313985Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.leases type=io.containerd.grpc.v1 Oct 28 05:15:23.010326 containerd[1595]: time="2025-10-28T05:15:23.010325877Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.namespaces type=io.containerd.grpc.v1 Oct 28 05:15:23.010432 containerd[1595]: time="2025-10-28T05:15:23.010344492Z" level=info msg="loading plugin" id=io.containerd.sandbox.store.v1.local type=io.containerd.sandbox.store.v1 Oct 28 05:15:23.010432 containerd[1595]: time="2025-10-28T05:15:23.010355613Z" level=info msg="loading plugin" id=io.containerd.cri.v1.images type=io.containerd.cri.v1 Oct 28 05:15:23.010483 containerd[1595]: time="2025-10-28T05:15:23.010450341Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\" for snapshotter \"overlayfs\"" Oct 28 05:15:23.010516 containerd[1595]: time="2025-10-28T05:15:23.010485176Z" level=info msg="Start snapshots syncer" Oct 28 05:15:23.010550 containerd[1595]: time="2025-10-28T05:15:23.010527285Z" level=info msg="loading plugin" id=io.containerd.cri.v1.runtime type=io.containerd.cri.v1 Oct 28 05:15:23.010843 containerd[1595]: time="2025-10-28T05:15:23.010790919Z" 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\"}" Oct 28 05:15:23.011016 containerd[1595]: time="2025-10-28T05:15:23.010861863Z" level=info msg="loading plugin" id=io.containerd.podsandbox.controller.v1.podsandbox type=io.containerd.podsandbox.controller.v1 Oct 28 05:15:23.011016 containerd[1595]: time="2025-10-28T05:15:23.010969013Z" level=info msg="loading plugin" id=io.containerd.sandbox.controller.v1.shim type=io.containerd.sandbox.controller.v1 Oct 28 05:15:23.011107 containerd[1595]: time="2025-10-28T05:15:23.011079050Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandbox-controllers type=io.containerd.grpc.v1 Oct 28 05:15:23.011107 containerd[1595]: time="2025-10-28T05:15:23.011104057Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandboxes type=io.containerd.grpc.v1 Oct 28 05:15:23.011147 containerd[1595]: time="2025-10-28T05:15:23.011116740Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.snapshots type=io.containerd.grpc.v1 Oct 28 05:15:23.011147 containerd[1595]: time="2025-10-28T05:15:23.011127591Z" level=info msg="loading plugin" id=io.containerd.streaming.v1.manager type=io.containerd.streaming.v1 Oct 28 05:15:23.011147 containerd[1595]: time="2025-10-28T05:15:23.011144462Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.streaming type=io.containerd.grpc.v1 Oct 28 05:15:23.011210 containerd[1595]: time="2025-10-28T05:15:23.011158308Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.tasks type=io.containerd.grpc.v1 Oct 28 05:15:23.011210 containerd[1595]: time="2025-10-28T05:15:23.011169920Z" level=info msg="loading plugin" id=io.containerd.transfer.v1.local type=io.containerd.transfer.v1 Oct 28 05:15:23.011210 containerd[1595]: time="2025-10-28T05:15:23.011193344Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.transfer type=io.containerd.grpc.v1 Oct 28 05:15:23.011261 containerd[1595]: time="2025-10-28T05:15:23.011216718Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.version type=io.containerd.grpc.v1 Oct 28 05:15:23.011261 containerd[1595]: time="2025-10-28T05:15:23.011238168Z" level=info msg="loading plugin" id=io.containerd.monitor.container.v1.restart type=io.containerd.monitor.container.v1 Oct 28 05:15:23.011304 containerd[1595]: time="2025-10-28T05:15:23.011294063Z" level=info msg="loading plugin" id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 Oct 28 05:15:23.011325 containerd[1595]: time="2025-10-28T05:15:23.011310774Z" 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 Oct 28 05:15:23.011325 containerd[1595]: time="2025-10-28T05:15:23.011320883Z" level=info msg="loading plugin" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 Oct 28 05:15:23.011363 containerd[1595]: time="2025-10-28T05:15:23.011332766Z" level=info msg="skip loading plugin" error="skip plugin: tracing endpoint not configured" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 Oct 28 05:15:23.011363 containerd[1595]: time="2025-10-28T05:15:23.011342344Z" level=info msg="loading plugin" id=io.containerd.ttrpc.v1.otelttrpc type=io.containerd.ttrpc.v1 Oct 28 05:15:23.011363 containerd[1595]: time="2025-10-28T05:15:23.011353254Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.healthcheck type=io.containerd.grpc.v1 Oct 28 05:15:23.011423 containerd[1595]: time="2025-10-28T05:15:23.011364094Z" level=info msg="loading plugin" id=io.containerd.nri.v1.nri type=io.containerd.nri.v1 Oct 28 05:15:23.011423 containerd[1595]: time="2025-10-28T05:15:23.011384342Z" level=info msg="runtime interface created" Oct 28 05:15:23.011423 containerd[1595]: time="2025-10-28T05:15:23.011391075Z" level=info msg="created NRI interface" Oct 28 05:15:23.011423 containerd[1595]: time="2025-10-28T05:15:23.011400423Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.cri type=io.containerd.grpc.v1 Oct 28 05:15:23.011423 containerd[1595]: time="2025-10-28T05:15:23.011412064Z" level=info msg="Connect containerd service" Oct 28 05:15:23.011543 containerd[1595]: time="2025-10-28T05:15:23.011451699Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Oct 28 05:15:23.012395 containerd[1595]: time="2025-10-28T05:15:23.012362276Z" level=error msg="failed to load cni during init, please check CRI plugin status before setting up network for pods" error="cni config load failed: no network config found in /etc/cni/net.d: cni plugin not initialized: failed to load cni config" Oct 28 05:15:23.164548 containerd[1595]: time="2025-10-28T05:15:23.164396344Z" level=info msg="Start subscribing containerd event" Oct 28 05:15:23.164548 containerd[1595]: time="2025-10-28T05:15:23.164509106Z" level=info msg="Start recovering state" Oct 28 05:15:23.164671 containerd[1595]: time="2025-10-28T05:15:23.164660810Z" level=info msg="Start event monitor" Oct 28 05:15:23.164709 containerd[1595]: time="2025-10-28T05:15:23.164688082Z" level=info msg="Start cni network conf syncer for default" Oct 28 05:15:23.164756 containerd[1595]: time="2025-10-28T05:15:23.164727205Z" level=info msg="Start streaming server" Oct 28 05:15:23.164756 containerd[1595]: time="2025-10-28T05:15:23.164746832Z" level=info msg="Registered namespace \"k8s.io\" with NRI" Oct 28 05:15:23.164794 containerd[1595]: time="2025-10-28T05:15:23.164758083Z" level=info msg="runtime interface starting up..." Oct 28 05:15:23.164794 containerd[1595]: time="2025-10-28T05:15:23.164767470Z" level=info msg="starting plugins..." Oct 28 05:15:23.164794 containerd[1595]: time="2025-10-28T05:15:23.164786887Z" level=info msg="Synchronizing NRI (plugin) with current runtime state" Oct 28 05:15:23.164921 containerd[1595]: time="2025-10-28T05:15:23.164893457Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Oct 28 05:15:23.165009 containerd[1595]: time="2025-10-28T05:15:23.164987744Z" level=info msg=serving... address=/run/containerd/containerd.sock Oct 28 05:15:23.165113 containerd[1595]: time="2025-10-28T05:15:23.165083092Z" level=info msg="containerd successfully booted in 0.178537s" Oct 28 05:15:23.165270 systemd[1]: Started containerd.service - containerd container runtime. Oct 28 05:15:23.410703 systemd-networkd[1498]: eth0: Gained IPv6LL Oct 28 05:15:23.414914 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Oct 28 05:15:23.417613 systemd[1]: Reached target network-online.target - Network is Online. Oct 28 05:15:23.421000 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Oct 28 05:15:23.424260 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Oct 28 05:15:23.460385 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Oct 28 05:15:23.470898 systemd[1]: coreos-metadata.service: Deactivated successfully. Oct 28 05:15:23.471234 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Oct 28 05:15:23.476224 systemd[1]: Starting etcd-member.service - etcd (System Application Container)... Oct 28 05:15:23.478514 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Oct 28 05:15:23.505228 (-wrapper)[1685]: etcd-member.service: Referenced but unset environment variable evaluates to an empty string: ETCD_OPTS Oct 28 05:15:23.793389 systemd[1]: Starting docker.service - Docker Application Container Engine... Oct 28 05:15:23.821880 (dockerd)[1698]: docker.service: Referenced but unset environment variable evaluates to an empty string: DOCKER_CGROUPS, DOCKER_OPTS, DOCKER_OPT_BIP, DOCKER_OPT_IPMASQ, DOCKER_OPT_MTU Oct 28 05:15:24.400958 dockerd[1698]: time="2025-10-28T05:15:24.400859384Z" level=info msg="Starting up" Oct 28 05:15:24.401854 dockerd[1698]: time="2025-10-28T05:15:24.401819535Z" level=info msg="OTEL tracing is not configured, using no-op tracer provider" Oct 28 05:15:24.424345 dockerd[1698]: time="2025-10-28T05:15:24.424289103Z" level=info msg="Creating a containerd client" address=/var/run/docker/libcontainerd/docker-containerd.sock timeout=1m0s Oct 28 05:15:24.487359 dockerd[1698]: time="2025-10-28T05:15:24.487278531Z" level=info msg="Loading containers: start." Oct 28 05:15:24.500493 kernel: Initializing XFRM netlink socket Oct 28 05:15:24.798851 systemd-networkd[1498]: docker0: Link UP Oct 28 05:15:24.803990 dockerd[1698]: time="2025-10-28T05:15:24.803938511Z" level=info msg="Loading containers: done." Oct 28 05:15:24.822395 systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck3844631824-merged.mount: Deactivated successfully. Oct 28 05:15:24.824307 dockerd[1698]: time="2025-10-28T05:15:24.824259210Z" level=warning msg="Not using native diff for overlay2, this may cause degraded performance for building images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled" storage-driver=overlay2 Oct 28 05:15:24.824382 dockerd[1698]: time="2025-10-28T05:15:24.824365449Z" level=info msg="Docker daemon" commit=6430e49a55babd9b8f4d08e70ecb2b68900770fe containerd-snapshotter=false storage-driver=overlay2 version=28.0.4 Oct 28 05:15:24.824486 dockerd[1698]: time="2025-10-28T05:15:24.824469164Z" level=info msg="Initializing buildkit" Oct 28 05:15:24.856437 dockerd[1698]: time="2025-10-28T05:15:24.856404874Z" level=info msg="Completed buildkit initialization" Oct 28 05:15:24.862665 dockerd[1698]: time="2025-10-28T05:15:24.862631331Z" level=info msg="Daemon has completed initialization" Oct 28 05:15:24.862770 dockerd[1698]: time="2025-10-28T05:15:24.862704849Z" level=info msg="API listen on /run/docker.sock" Oct 28 05:15:24.862960 systemd[1]: Started docker.service - Docker Application Container Engine. Oct 28 05:15:24.865096 etcd-wrapper[1690]: Error response from daemon: No such container: etcd-member Oct 28 05:15:24.973836 etcd-wrapper[1899]: Error response from daemon: No such container: etcd-member Oct 28 05:15:25.011214 etcd-wrapper[1920]: Unable to find image 'quay.io/coreos/etcd:v3.5.22' locally Oct 28 05:15:25.952060 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Oct 28 05:15:25.955139 systemd[1]: Started sshd@0-10.0.0.72:22-10.0.0.1:56292.service - OpenSSH per-connection server daemon (10.0.0.1:56292). Oct 28 05:15:26.055821 etcd-wrapper[1920]: v3.5.22: Pulling from coreos/etcd Oct 28 05:15:26.061239 sshd[1933]: Accepted publickey for core from 10.0.0.1 port 56292 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:26.063718 sshd-session[1933]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:26.070638 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Oct 28 05:15:26.073546 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Oct 28 05:15:26.081809 systemd-logind[1570]: New session 1 of user core. Oct 28 05:15:26.102079 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Oct 28 05:15:26.107396 systemd[1]: Starting user@500.service - User Manager for UID 500... Oct 28 05:15:26.125152 (systemd)[1938]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Oct 28 05:15:26.127439 systemd-logind[1570]: New session c1 of user core. Oct 28 05:15:26.275634 systemd[1938]: Queued start job for default target default.target. Oct 28 05:15:26.293783 systemd[1938]: Created slice app.slice - User Application Slice. Oct 28 05:15:26.293810 systemd[1938]: Reached target paths.target - Paths. Oct 28 05:15:26.293850 systemd[1938]: Reached target timers.target - Timers. Oct 28 05:15:26.295470 systemd[1938]: Starting dbus.socket - D-Bus User Message Bus Socket... Oct 28 05:15:26.307543 etcd-wrapper[1920]: f5083dc2076d: Pulling fs layer Oct 28 05:15:26.307543 etcd-wrapper[1920]: 2ae710cd8bfe: Pulling fs layer Oct 28 05:15:26.307543 etcd-wrapper[1920]: d462aa345367: Pulling fs layer Oct 28 05:15:26.307543 etcd-wrapper[1920]: 0f8b424aa0b9: Pulling fs layer Oct 28 05:15:26.307543 etcd-wrapper[1920]: d557676654e5: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: c8022d07192e: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: d858cbc252ad: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 1069fc2daed1: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: b40161cd83fc: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 5318d93a3a65: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 307c1adadb60: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 60a82e1b19c6: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 6f77055ebb6e: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: 67f98bbc9874: Pulling fs layer Oct 28 05:15:26.307794 etcd-wrapper[1920]: d557676654e5: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: c8022d07192e: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: d858cbc252ad: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 1069fc2daed1: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: b40161cd83fc: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 5318d93a3a65: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 307c1adadb60: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 60a82e1b19c6: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 6f77055ebb6e: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 67f98bbc9874: Waiting Oct 28 05:15:26.307794 etcd-wrapper[1920]: 0f8b424aa0b9: Waiting Oct 28 05:15:26.311505 systemd[1938]: Listening on dbus.socket - D-Bus User Message Bus Socket. Oct 28 05:15:26.311659 systemd[1938]: Reached target sockets.target - Sockets. Oct 28 05:15:26.311706 systemd[1938]: Reached target basic.target - Basic System. Oct 28 05:15:26.311751 systemd[1938]: Reached target default.target - Main User Target. Oct 28 05:15:26.311802 systemd[1938]: Startup finished in 177ms. Oct 28 05:15:26.312174 systemd[1]: Started user@500.service - User Manager for UID 500. Oct 28 05:15:26.315502 systemd[1]: Started session-1.scope - Session 1 of User core. Oct 28 05:15:26.329392 systemd[1]: Started sshd@1-10.0.0.72:22-10.0.0.1:56294.service - OpenSSH per-connection server daemon (10.0.0.1:56294). Oct 28 05:15:26.478229 sshd[1949]: Accepted publickey for core from 10.0.0.1 port 56294 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:26.480251 sshd-session[1949]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:26.485412 systemd-logind[1570]: New session 2 of user core. Oct 28 05:15:26.498643 systemd[1]: Started session-2.scope - Session 2 of User core. Oct 28 05:15:26.514932 sshd[1952]: Connection closed by 10.0.0.1 port 56294 Oct 28 05:15:26.515323 sshd-session[1949]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:26.533068 systemd[1]: sshd@1-10.0.0.72:22-10.0.0.1:56294.service: Deactivated successfully. Oct 28 05:15:26.535321 systemd[1]: session-2.scope: Deactivated successfully. Oct 28 05:15:26.536354 systemd-logind[1570]: Session 2 logged out. Waiting for processes to exit. Oct 28 05:15:26.541304 systemd[1]: Started sshd@2-10.0.0.72:22-10.0.0.1:56296.service - OpenSSH per-connection server daemon (10.0.0.1:56296). Oct 28 05:15:26.544371 systemd-logind[1570]: Removed session 2. Oct 28 05:15:26.569331 etcd-wrapper[1920]: 2ae710cd8bfe: Verifying Checksum Oct 28 05:15:26.569331 etcd-wrapper[1920]: 2ae710cd8bfe: Download complete Oct 28 05:15:26.589132 etcd-wrapper[1920]: f5083dc2076d: Verifying Checksum Oct 28 05:15:26.589132 etcd-wrapper[1920]: f5083dc2076d: Download complete Oct 28 05:15:26.622733 sshd[1958]: Accepted publickey for core from 10.0.0.1 port 56296 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:26.624918 sshd-session[1958]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:26.626321 etcd-wrapper[1920]: d462aa345367: Download complete Oct 28 05:15:26.630336 etcd-wrapper[1920]: f5083dc2076d: Pull complete Oct 28 05:15:26.630695 systemd-logind[1570]: New session 3 of user core. Oct 28 05:15:26.642717 systemd[1]: Started session-3.scope - Session 3 of User core. Oct 28 05:15:26.650745 systemd[1]: var-lib-docker-overlay2-e9e9f24cb0cf864abc189283e21fe5eb969e05d37830ebee1c291c2aeba8b824-merged.mount: Deactivated successfully. Oct 28 05:15:26.668930 sshd[1970]: Connection closed by 10.0.0.1 port 56296 Oct 28 05:15:26.669210 sshd-session[1958]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:26.673808 systemd[1]: sshd@2-10.0.0.72:22-10.0.0.1:56296.service: Deactivated successfully. Oct 28 05:15:26.675655 etcd-wrapper[1920]: 2ae710cd8bfe: Pull complete Oct 28 05:15:26.676143 systemd[1]: session-3.scope: Deactivated successfully. Oct 28 05:15:26.677107 systemd-logind[1570]: Session 3 logged out. Waiting for processes to exit. Oct 28 05:15:26.678660 systemd-logind[1570]: Removed session 3. Oct 28 05:15:26.890830 etcd-wrapper[1920]: c8022d07192e: Verifying Checksum Oct 28 05:15:26.890830 etcd-wrapper[1920]: c8022d07192e: Download complete Oct 28 05:15:26.891908 etcd-wrapper[1920]: d557676654e5: Verifying Checksum Oct 28 05:15:26.891908 etcd-wrapper[1920]: d557676654e5: Download complete Oct 28 05:15:27.040890 etcd-wrapper[1920]: 0f8b424aa0b9: Verifying Checksum Oct 28 05:15:27.040890 etcd-wrapper[1920]: 0f8b424aa0b9: Download complete Oct 28 05:15:27.142283 etcd-wrapper[1920]: d858cbc252ad: Download complete Oct 28 05:15:27.165403 etcd-wrapper[1920]: 1069fc2daed1: Verifying Checksum Oct 28 05:15:27.165403 etcd-wrapper[1920]: 1069fc2daed1: Download complete Oct 28 05:15:27.185939 systemd[1]: var-lib-docker-overlay2-c40f3f126442ffdf483f09e090fad76c3443dcc777050905b863716c8d5050de-merged.mount: Deactivated successfully. Oct 28 05:15:27.245991 etcd-wrapper[1920]: d462aa345367: Pull complete Oct 28 05:15:27.261257 systemd[1]: var-lib-docker-overlay2-7306b40a926496b84b57e8720b57465edc9163439ba7a5865d425cf5e4dba2a3-merged.mount: Deactivated successfully. Oct 28 05:15:27.269655 etcd-wrapper[1920]: 0f8b424aa0b9: Pull complete Oct 28 05:15:27.284906 systemd[1]: var-lib-docker-overlay2-e424eb51b85d1684897507b59f2a5e2cd625d9aad16b5a301e4017ee5b2eaf71-merged.mount: Deactivated successfully. Oct 28 05:15:27.288850 etcd-wrapper[1920]: b40161cd83fc: Download complete Oct 28 05:15:27.292189 etcd-wrapper[1920]: d557676654e5: Pull complete Oct 28 05:15:27.321755 etcd-wrapper[1920]: c8022d07192e: Pull complete Oct 28 05:15:27.345962 etcd-wrapper[1920]: d858cbc252ad: Pull complete Oct 28 05:15:27.371712 etcd-wrapper[1920]: 1069fc2daed1: Pull complete Oct 28 05:15:27.381159 etcd-wrapper[1920]: 5318d93a3a65: Download complete Oct 28 05:15:27.401389 etcd-wrapper[1920]: b40161cd83fc: Pull complete Oct 28 05:15:27.428554 etcd-wrapper[1920]: 5318d93a3a65: Pull complete Oct 28 05:15:27.432036 etcd-wrapper[1920]: 307c1adadb60: Download complete Oct 28 05:15:27.456678 etcd-wrapper[1920]: 307c1adadb60: Pull complete Oct 28 05:15:27.737213 etcd-wrapper[1920]: 6f77055ebb6e: Verifying Checksum Oct 28 05:15:27.737213 etcd-wrapper[1920]: 6f77055ebb6e: Download complete Oct 28 05:15:27.795441 etcd-wrapper[1920]: 60a82e1b19c6: Verifying Checksum Oct 28 05:15:27.795441 etcd-wrapper[1920]: 60a82e1b19c6: Download complete Oct 28 05:15:27.796491 etcd-wrapper[1920]: 67f98bbc9874: Verifying Checksum Oct 28 05:15:27.796491 etcd-wrapper[1920]: 67f98bbc9874: Download complete Oct 28 05:15:28.064073 etcd-wrapper[1920]: 60a82e1b19c6: Pull complete Oct 28 05:15:28.234700 etcd-wrapper[1920]: 6f77055ebb6e: Pull complete Oct 28 05:15:28.328887 systemd[1]: var-lib-docker-overlay2-a19141a208a8bb08d678bb02677c1feabb6db2c98d14ea3b2e34c9cf641f6455-merged.mount: Deactivated successfully. Oct 28 05:15:28.382583 etcd-wrapper[1920]: 67f98bbc9874: Pull complete Oct 28 05:15:28.392728 etcd-wrapper[1920]: Digest: sha256:51efcfc4f3a863c072ebe745942f790878c2a268e713a6d140c4f2593271adc6 Oct 28 05:15:28.396129 etcd-wrapper[1920]: Status: Downloaded newer image for quay.io/coreos/etcd:v3.5.22 Oct 28 05:15:28.455912 containerd[1595]: time="2025-10-28T05:15:28.455727088Z" level=info msg="connecting to shim 4422a4aaff350e66a482e640e409be8a87f3d9952abd1656614cf7a54c629afa" address="unix:///run/containerd/s/adbfc7119f90156e169ad7414174a9cbdbbc3bb5c067920637e6f7d4908526a0" namespace=moby protocol=ttrpc version=3 Oct 28 05:15:28.487607 systemd[1]: Started docker-4422a4aaff350e66a482e640e409be8a87f3d9952abd1656614cf7a54c629afa.scope - libcontainer container 4422a4aaff350e66a482e640e409be8a87f3d9952abd1656614cf7a54c629afa. Oct 28 05:15:28.503708 systemd-resolved[1328]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.559089Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_DATA_DIR","variable-value":"/var/lib/etcd"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.559274Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_NAME","variable-value":"c48b096d43c04bbe86df3af6f6588e0f"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559298Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_URL=quay.io/coreos/etcd"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559308Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_TAG=v3.5.22"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559313Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_USER=etcd"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559318Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_SSL_DIR=/etc/ssl/certs"} Oct 28 05:15:28.559523 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559340Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Oct 28 05:15:28.560190 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.559502Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["/usr/local/bin/etcd","--listen-client-urls=http://0.0.0.0:2379","--advertise-client-urls=http://10.0.0.72:2379"]} Oct 28 05:15:28.560190 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.559680Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Oct 28 05:15:28.560190 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.559712Z","caller":"embed/etcd.go:140","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} Oct 28 05:15:28.560670 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.560521Z","caller":"embed/etcd.go:148","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} Oct 28 05:15:28.560888 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.560737Z","caller":"embed/etcd.go:323","msg":"starting an etcd server","etcd-version":"3.5.22","git-sha":"7862c85","go-version":"go1.23.11","go-os":"linux","go-arch":"amd64","max-cpu-set":4,"max-cpu-available":4,"member-initialized":false,"name":"c48b096d43c04bbe86df3af6f6588e0f","data-dir":"/var/lib/etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/lib/etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://10.0.0.72:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"c48b096d43c04bbe86df3af6f6588e0f=http://localhost:2380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} Oct 28 05:15:28.563605 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.563429Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"2.257203ms"} Oct 28 05:15:28.568319 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568111Z","caller":"etcdserver/raft.go:507","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} Oct 28 05:15:28.568319 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568173Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} Oct 28 05:15:28.568319 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568198Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} Oct 28 05:15:28.568319 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568207Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} Oct 28 05:15:28.568319 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568216Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} Oct 28 05:15:28.568574 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.568266Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Oct 28 05:15:28.572117 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:15:28.571929Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} Oct 28 05:15:28.573086 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.572900Z","caller":"mvcc/kvstore.go:425","msg":"kvstore restored","current-rev":1} Oct 28 05:15:28.573086 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.572927Z","caller":"etcdserver/server.go:628","msg":"restore consistentIndex","index":0} Oct 28 05:15:28.573884 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.573720Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} Oct 28 05:15:28.575066 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.574621Z","caller":"etcdserver/server.go:875","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.22","cluster-version":"to_be_decided"} Oct 28 05:15:28.575066 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.574832Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Oct 28 05:15:28.575253 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.575086Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} Oct 28 05:15:28.575387 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.575245Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} Oct 28 05:15:28.575479 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.575317Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} Oct 28 05:15:28.575895 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.575232Z","caller":"etcdserver/server.go:759","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"8e9e05c52164694d","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"} Oct 28 05:15:28.576445 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.576258Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Oct 28 05:15:28.577518 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.576607Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"],"added-peer-is-learner":false} Oct 28 05:15:28.577892 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.577700Z","caller":"embed/etcd.go:633","msg":"serving peer traffic","address":"127.0.0.1:2380"} Oct 28 05:15:28.577966 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.577750Z","caller":"embed/etcd.go:292","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://10.0.0.72:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} Oct 28 05:15:28.577966 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.577760Z","caller":"embed/etcd.go:603","msg":"cmux::serve","address":"127.0.0.1:2380"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.668901Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.668939Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.668956Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.668967Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.668990Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669000Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} Oct 28 05:15:28.669292 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669006Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} Oct 28 05:15:28.669986 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669632Z","caller":"etcdserver/server.go:2144","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:c48b096d43c04bbe86df3af6f6588e0f ClientURLs:[http://10.0.0.72:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} Oct 28 05:15:28.669986 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669776Z","caller":"etcdserver/server.go:2697","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} Oct 28 05:15:28.670175 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669813Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} Oct 28 05:15:28.670509 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.669756Z","caller":"embed/serve.go:124","msg":"ready to serve client requests"} Oct 28 05:15:28.670726 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.670477Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} Oct 28 05:15:28.670927 systemd[1]: Started etcd-member.service - etcd (System Application Container). Oct 28 05:15:28.671402 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.670772Z","caller":"membership/cluster.go:587","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} Oct 28 05:15:28.671402 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.670867Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} Oct 28 05:15:28.671402 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.670890Z","caller":"etcdserver/server.go:2721","msg":"cluster version is updated","cluster-version":"3.5"} Oct 28 05:15:28.671402 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.671215Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Oct 28 05:15:28.671349 systemd[1]: Reached target multi-user.target - Multi-User System. Oct 28 05:15:28.671746 systemd[1]: Startup finished in 2.995s (kernel) + 4.426s (initrd) + 10.222s (userspace) = 17.644s. Oct 28 05:15:28.672131 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:15:28.671965Z","caller":"embed/serve.go:210","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} Oct 28 05:15:29.187278 systemd[1]: var-lib-docker-overlay2-d9fcbfb4ce5199cb691f3b5cc3b1778e7d5c8d467d6aa79163a455a152f44ea9\x2dinit-merged.mount: Deactivated successfully. Oct 28 05:15:36.687781 systemd[1]: Started sshd@3-10.0.0.72:22-10.0.0.1:48380.service - OpenSSH per-connection server daemon (10.0.0.1:48380). Oct 28 05:15:36.749121 sshd[2095]: Accepted publickey for core from 10.0.0.1 port 48380 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:36.750501 sshd-session[2095]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:36.755142 systemd-logind[1570]: New session 4 of user core. Oct 28 05:15:36.764590 systemd[1]: Started session-4.scope - Session 4 of User core. Oct 28 05:15:36.776910 sshd[2098]: Connection closed by 10.0.0.1 port 48380 Oct 28 05:15:36.777299 sshd-session[2095]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:36.797926 systemd[1]: sshd@3-10.0.0.72:22-10.0.0.1:48380.service: Deactivated successfully. Oct 28 05:15:36.799634 systemd[1]: session-4.scope: Deactivated successfully. Oct 28 05:15:36.800382 systemd-logind[1570]: Session 4 logged out. Waiting for processes to exit. Oct 28 05:15:36.803031 systemd[1]: Started sshd@4-10.0.0.72:22-10.0.0.1:48386.service - OpenSSH per-connection server daemon (10.0.0.1:48386). Oct 28 05:15:36.803713 systemd-logind[1570]: Removed session 4. Oct 28 05:15:36.874038 sshd[2104]: Accepted publickey for core from 10.0.0.1 port 48386 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:36.875743 sshd-session[2104]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:36.880606 systemd-logind[1570]: New session 5 of user core. Oct 28 05:15:36.898614 systemd[1]: Started session-5.scope - Session 5 of User core. Oct 28 05:15:36.908121 sshd[2107]: Connection closed by 10.0.0.1 port 48386 Oct 28 05:15:36.908429 sshd-session[2104]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:36.925908 systemd[1]: sshd@4-10.0.0.72:22-10.0.0.1:48386.service: Deactivated successfully. Oct 28 05:15:36.927524 systemd[1]: session-5.scope: Deactivated successfully. Oct 28 05:15:36.928246 systemd-logind[1570]: Session 5 logged out. Waiting for processes to exit. Oct 28 05:15:36.931009 systemd[1]: Started sshd@5-10.0.0.72:22-10.0.0.1:48398.service - OpenSSH per-connection server daemon (10.0.0.1:48398). Oct 28 05:15:36.931610 systemd-logind[1570]: Removed session 5. Oct 28 05:15:36.985834 sshd[2113]: Accepted publickey for core from 10.0.0.1 port 48398 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:36.987785 sshd-session[2113]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:36.992519 systemd-logind[1570]: New session 6 of user core. Oct 28 05:15:37.006724 systemd[1]: Started session-6.scope - Session 6 of User core. Oct 28 05:15:37.021903 sshd[2116]: Connection closed by 10.0.0.1 port 48398 Oct 28 05:15:37.022321 sshd-session[2113]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:37.036906 systemd[1]: sshd@5-10.0.0.72:22-10.0.0.1:48398.service: Deactivated successfully. Oct 28 05:15:37.038981 systemd[1]: session-6.scope: Deactivated successfully. Oct 28 05:15:37.039893 systemd-logind[1570]: Session 6 logged out. Waiting for processes to exit. Oct 28 05:15:37.043341 systemd[1]: Started sshd@6-10.0.0.72:22-10.0.0.1:48408.service - OpenSSH per-connection server daemon (10.0.0.1:48408). Oct 28 05:15:37.044337 systemd-logind[1570]: Removed session 6. Oct 28 05:15:37.104642 sshd[2122]: Accepted publickey for core from 10.0.0.1 port 48408 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:37.106660 sshd-session[2122]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:37.111962 systemd-logind[1570]: New session 7 of user core. Oct 28 05:15:37.121616 systemd[1]: Started session-7.scope - Session 7 of User core. Oct 28 05:15:37.133328 sshd[2125]: Connection closed by 10.0.0.1 port 48408 Oct 28 05:15:37.133928 sshd-session[2122]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:37.143037 systemd[1]: sshd@6-10.0.0.72:22-10.0.0.1:48408.service: Deactivated successfully. Oct 28 05:15:37.144901 systemd[1]: session-7.scope: Deactivated successfully. Oct 28 05:15:37.145837 systemd-logind[1570]: Session 7 logged out. Waiting for processes to exit. Oct 28 05:15:37.148849 systemd[1]: Started sshd@7-10.0.0.72:22-10.0.0.1:48414.service - OpenSSH per-connection server daemon (10.0.0.1:48414). Oct 28 05:15:37.149695 systemd-logind[1570]: Removed session 7. Oct 28 05:15:37.215763 sshd[2133]: Accepted publickey for core from 10.0.0.1 port 48414 ssh2: RSA SHA256:fnPK7ZFusTyP70xk0T3ldjOg8cdR8K1Md9pjQBlXC4c Oct 28 05:15:37.217157 sshd-session[2133]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 28 05:15:37.221634 systemd-logind[1570]: New session 8 of user core. Oct 28 05:15:37.235605 systemd[1]: Started session-8.scope - Session 8 of User core. Oct 28 05:15:37.313698 sshd[2136]: Connection closed by 10.0.0.1 port 48414 Oct 28 05:15:37.313992 sshd-session[2133]: pam_unix(sshd:session): session closed for user core Oct 28 05:15:37.320097 systemd[1]: sshd@7-10.0.0.72:22-10.0.0.1:48414.service: Deactivated successfully. Oct 28 05:15:37.322282 systemd[1]: session-8.scope: Deactivated successfully. Oct 28 05:15:37.323063 systemd-logind[1570]: Session 8 logged out. Waiting for processes to exit. Oct 28 05:15:37.324372 systemd-logind[1570]: Removed session 8. Oct 28 05:16:08.058501 update_engine[1577]: I20251028 05:16:08.058357 1577 update_attempter.cc:509] Updating boot flags... Oct 28 05:16:27.212243 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:27.211534Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"142.094263ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:14"} Oct 28 05:16:27.212243 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.211710Z","caller":"traceutil/trace.go:171","msg":"trace[1284017243] linearizableReadLoop","detail":"{readStateIndex:56; appliedIndex:54; }","duration":"137.790652ms","start":"2025-10-28T05:16:27.073908Z","end":"2025-10-28T05:16:27.211699Z","steps":["trace[1284017243] 'read index received' (duration: 95.919849ms)","trace[1284017243] 'applied index is now lower than readState.Index' (duration: 41.870363ms)"],"step_count":2} Oct 28 05:16:27.212243 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:27.211754Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"137.841579ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/limitranges\" limit:1 ","response":"range_response_count:0 size:4"} Oct 28 05:16:27.212243 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.211778Z","caller":"traceutil/trace.go:171","msg":"trace[2134185927] range","detail":"{range_begin:/registry/limitranges; range_end:; response_count:0; response_revision:52; }","duration":"137.867737ms","start":"2025-10-28T05:16:27.073905Z","end":"2025-10-28T05:16:27.211773Z","steps":["trace[2134185927] 'agreement among raft nodes before linearized reading' (duration: 137.824967ms)"],"step_count":1} Oct 28 05:16:27.213072 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.211804Z","caller":"traceutil/trace.go:171","msg":"trace[191028747] transaction","detail":"{read_only:false; response_revision:52; number_of_response:1; }","duration":"193.001396ms","start":"2025-10-28T05:16:27.018795Z","end":"2025-10-28T05:16:27.211797Z","steps":["trace[191028747] 'process raft request' (duration: 192.853057ms)"],"step_count":1} Oct 28 05:16:27.213072 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.211875Z","caller":"traceutil/trace.go:171","msg":"trace[1730448660] transaction","detail":"{read_only:false; response_revision:51; number_of_response:1; }","duration":"193.964819ms","start":"2025-10-28T05:16:27.017867Z","end":"2025-10-28T05:16:27.211832Z","steps":["trace[1730448660] 'process raft request' (duration: 51.122469ms)","trace[1730448660] 'compare' (duration: 142.01851ms)"],"step_count":2} Oct 28 05:16:27.496812 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.496340Z","caller":"traceutil/trace.go:171","msg":"trace[635664598] transaction","detail":"{read_only:false; response_revision:56; number_of_response:1; }","duration":"230.762294ms","start":"2025-10-28T05:16:27.265559Z","end":"2025-10-28T05:16:27.496321Z","steps":["trace[635664598] 'process raft request' (duration: 185.568828ms)","trace[635664598] 'compare' (duration: 45.060816ms)"],"step_count":2} Oct 28 05:16:27.496812 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.496397Z","caller":"traceutil/trace.go:171","msg":"trace[2088124] transaction","detail":"{read_only:false; response_revision:57; number_of_response:1; }","duration":"196.20808ms","start":"2025-10-28T05:16:27.300177Z","end":"2025-10-28T05:16:27.496385Z","steps":["trace[2088124] 'process raft request' (duration: 196.09134ms)"],"step_count":1} Oct 28 05:16:27.845217 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:27.844716Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"200.785608ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:14"} Oct 28 05:16:27.845217 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.844826Z","caller":"traceutil/trace.go:171","msg":"trace[1503198515] transaction","detail":"{read_only:false; response_revision:61; number_of_response:1; }","duration":"324.986181ms","start":"2025-10-28T05:16:27.519830Z","end":"2025-10-28T05:16:27.844817Z","steps":["trace[1503198515] 'process raft request' (duration: 324.953038ms)"],"step_count":1} Oct 28 05:16:27.845403 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:27.844864Z","caller":"traceutil/trace.go:171","msg":"trace[831204478] transaction","detail":"{read_only:false; response_revision:60; number_of_response:1; }","duration":"325.313216ms","start":"2025-10-28T05:16:27.519539Z","end":"2025-10-28T05:16:27.844852Z","steps":["trace[831204478] 'process raft request' (duration: 124.348962ms)","trace[831204478] 'compare' (duration: 200.688114ms)"],"step_count":2} Oct 28 05:16:27.845403 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:27.844918Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:27.519530Z","time spent":"325.365544ms","remote":"10.0.0.79:54526","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":571,"response count":0,"response size":38,"request content":"compare: success:> failure:<>"} Oct 28 05:16:27.845403 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:27.844869Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:27.519823Z","time spent":"325.021316ms","remote":"10.0.0.79:54526","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1028,"response count":0,"response size":38,"request content":"compare: success:> failure: >"} Oct 28 05:16:28.132539 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:28.132086Z","caller":"traceutil/trace.go:171","msg":"trace[335871891] transaction","detail":"{read_only:false; response_revision:72; number_of_response:1; }","duration":"118.738871ms","start":"2025-10-28T05:16:28.013332Z","end":"2025-10-28T05:16:28.132070Z","steps":["trace[335871891] 'process raft request' (duration: 70.595962ms)","trace[335871891] 'compare' (duration: 48.059331ms)"],"step_count":2} Oct 28 05:16:30.258301 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:30.257943Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"101.687592ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-node-lease/localhost\" limit:1 ","response":"range_response_count:0 size:5"} Oct 28 05:16:30.258301 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:30.258008Z","caller":"traceutil/trace.go:171","msg":"trace[328010671] range","detail":"{range_begin:/registry/leases/kube-node-lease/localhost; range_end:; response_count:0; response_revision:234; }","duration":"101.764326ms","start":"2025-10-28T05:16:30.156233Z","end":"2025-10-28T05:16:30.257998Z","steps":["trace[328010671] 'agreement among raft nodes before linearized reading' (duration: 101.671722ms)"],"step_count":1} Oct 28 05:16:31.727094 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:31.726586Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.962115ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/kube-system\" limit:1 ","response":"range_response_count:1 size:351"} Oct 28 05:16:31.727094 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:31.726653Z","caller":"traceutil/trace.go:171","msg":"trace[1183151901] range","detail":"{range_begin:/registry/namespaces/kube-system; range_end:; response_count:1; response_revision:282; }","duration":"120.032596ms","start":"2025-10-28T05:16:31.606608Z","end":"2025-10-28T05:16:31.726640Z","steps":["trace[1183151901] 'range keys from in-memory index tree' (duration: 119.92271ms)"],"step_count":1} Oct 28 05:16:36.337239 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.336842Z","caller":"traceutil/trace.go:171","msg":"trace[169761296] transaction","detail":"{read_only:false; response_revision:318; number_of_response:1; }","duration":"178.982991ms","start":"2025-10-28T05:16:36.157843Z","end":"2025-10-28T05:16:36.336825Z","steps":["trace[169761296] 'process raft request' (duration: 136.200684ms)","trace[169761296] 'compare' (duration: 42.653886ms)"],"step_count":2} Oct 28 05:16:36.337239 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.336945Z","caller":"traceutil/trace.go:171","msg":"trace[1705342359] transaction","detail":"{read_only:false; response_revision:319; number_of_response:1; }","duration":"127.14187ms","start":"2025-10-28T05:16:36.209752Z","end":"2025-10-28T05:16:36.336893Z","steps":["trace[1705342359] 'process raft request' (duration: 127.076377ms)"],"step_count":1} Oct 28 05:16:36.337239 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.336909Z","caller":"traceutil/trace.go:171","msg":"trace[973490940] linearizableReadLoop","detail":"{readStateIndex:328; appliedIndex:327; }","duration":"130.138079ms","start":"2025-10-28T05:16:36.206746Z","end":"2025-10-28T05:16:36.336884Z","steps":["trace[973490940] 'read index received' (duration: 87.294377ms)","trace[973490940] 'applied index is now lower than readState.Index' (duration: 42.841739ms)"],"step_count":2} Oct 28 05:16:36.338008 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:36.337148Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"130.382579ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/service-cidrs-controller\" limit:1 ","response":"range_response_count:1 size:214"} Oct 28 05:16:36.338252 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.337201Z","caller":"traceutil/trace.go:171","msg":"trace[78944503] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/service-cidrs-controller; range_end:; response_count:1; response_revision:319; }","duration":"130.463432ms","start":"2025-10-28T05:16:36.206724Z","end":"2025-10-28T05:16:36.337188Z","steps":["trace[78944503] 'agreement among raft nodes before linearized reading' (duration: 130.254769ms)"],"step_count":1} Oct 28 05:16:36.546375 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.545899Z","caller":"traceutil/trace.go:171","msg":"trace[1572718828] linearizableReadLoop","detail":"{readStateIndex:331; appliedIndex:330; }","duration":"139.123536ms","start":"2025-10-28T05:16:36.406759Z","end":"2025-10-28T05:16:36.545882Z","steps":["trace[1572718828] 'read index received' (duration: 48.799705ms)","trace[1572718828] 'applied index is now lower than readState.Index' (duration: 90.32331ms)"],"step_count":2} Oct 28 05:16:36.546375 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:36.546028Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"139.259001ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/legacy-service-account-token-cleaner\" limit:1 ","response":"range_response_count:1 size:238"} Oct 28 05:16:36.546375 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.546017Z","caller":"traceutil/trace.go:171","msg":"trace[929476352] transaction","detail":"{read_only:false; response_revision:321; number_of_response:1; }","duration":"156.370638ms","start":"2025-10-28T05:16:36.389616Z","end":"2025-10-28T05:16:36.545986Z","steps":["trace[929476352] 'process raft request' (duration: 65.920681ms)","trace[929476352] 'compare' (duration: 90.269328ms)"],"step_count":2} Oct 28 05:16:36.546709 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.546050Z","caller":"traceutil/trace.go:171","msg":"trace[662326625] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/legacy-service-account-token-cleaner; range_end:; response_count:1; response_revision:321; }","duration":"139.297193ms","start":"2025-10-28T05:16:36.406747Z","end":"2025-10-28T05:16:36.546044Z","steps":["trace[662326625] 'agreement among raft nodes before linearized reading' (duration: 139.225418ms)"],"step_count":1} Oct 28 05:16:36.831248 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:36.830831Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"173.706858ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/bootstrap-signer\" limit:1 ","response":"range_response_count:1 size:197"} Oct 28 05:16:36.831248 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.830909Z","caller":"traceutil/trace.go:171","msg":"trace[1274055886] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/bootstrap-signer; range_end:; response_count:1; response_revision:321; }","duration":"173.80373ms","start":"2025-10-28T05:16:36.657094Z","end":"2025-10-28T05:16:36.830897Z","steps":["trace[1274055886] 'range keys from in-memory index tree' (duration: 173.631277ms)"],"step_count":1} Oct 28 05:16:36.831436 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:36.831121Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"124.684374ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/deployment-controller\" limit:1 ","response":"range_response_count:1 size:207"} Oct 28 05:16:36.831436 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:36.831172Z","caller":"traceutil/trace.go:171","msg":"trace[1036671276] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/deployment-controller; range_end:; response_count:1; response_revision:321; }","duration":"124.747742ms","start":"2025-10-28T05:16:36.706413Z","end":"2025-10-28T05:16:36.831160Z","steps":["trace[1036671276] 'range keys from in-memory index tree' (duration: 124.353521ms)"],"step_count":1} Oct 28 05:16:37.146149 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.145643Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"200.706039ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Oct 28 05:16:37.146149 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.145742Z","caller":"traceutil/trace.go:171","msg":"trace[156969999] transaction","detail":"{read_only:false; response_revision:323; number_of_response:1; }","duration":"267.53085ms","start":"2025-10-28T05:16:36.878198Z","end":"2025-10-28T05:16:37.145729Z","steps":["trace[156969999] 'process raft request' (duration: 66.703973ms)","trace[156969999] 'compare' (duration: 200.629486ms)"],"step_count":2} Oct 28 05:16:37.184958 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.184556Z","caller":"traceutil/trace.go:171","msg":"trace[1758122131] linearizableReadLoop","detail":"{readStateIndex:334; appliedIndex:332; }","duration":"278.121963ms","start":"2025-10-28T05:16:36.906418Z","end":"2025-10-28T05:16:37.184540Z","steps":["trace[1758122131] 'read index received' (duration: 38.568148ms)","trace[1758122131] 'applied index is now lower than readState.Index' (duration: 239.552873ms)"],"step_count":2} Oct 28 05:16:37.184958 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.184615Z","caller":"traceutil/trace.go:171","msg":"trace[981581882] transaction","detail":"{read_only:false; response_revision:324; number_of_response:1; }","duration":"303.924712ms","start":"2025-10-28T05:16:36.880654Z","end":"2025-10-28T05:16:37.184579Z","steps":["trace[981581882] 'process raft request' (duration: 303.780712ms)"],"step_count":1} Oct 28 05:16:37.184958 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.184655Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"278.223865ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/endpoint-controller\" limit:1 ","response":"range_response_count:1 size:203"} Oct 28 05:16:37.184958 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.184680Z","caller":"traceutil/trace.go:171","msg":"trace[1520973254] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/endpoint-controller; range_end:; response_count:1; response_revision:324; }","duration":"278.259412ms","start":"2025-10-28T05:16:36.906414Z","end":"2025-10-28T05:16:37.184674Z","steps":["trace[1520973254] 'agreement among raft nodes before linearized reading' (duration: 278.207795ms)"],"step_count":1} Oct 28 05:16:37.185231 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.184745Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:36.880643Z","time spent":"304.030322ms","remote":"10.0.0.79:54024","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":4010,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.434599 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.433860Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"170.469662ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Oct 28 05:16:37.434599 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.433991Z","caller":"traceutil/trace.go:171","msg":"trace[872507777] linearizableReadLoop","detail":"{readStateIndex:337; appliedIndex:334; }","duration":"249.37707ms","start":"2025-10-28T05:16:37.184606Z","end":"2025-10-28T05:16:37.433983Z","steps":["trace[872507777] 'read index received' (duration: 78.825914ms)","trace[872507777] 'applied index is now lower than readState.Index' (duration: 170.550685ms)"],"step_count":2} Oct 28 05:16:37.434599 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.433994Z","caller":"traceutil/trace.go:171","msg":"trace[1890945183] transaction","detail":"{read_only:false; response_revision:325; number_of_response:1; }","duration":"372.36819ms","start":"2025-10-28T05:16:37.061610Z","end":"2025-10-28T05:16:37.433978Z","steps":["trace[1890945183] 'process raft request' (duration: 201.735621ms)","trace[1890945183] 'compare' (duration: 170.372209ms)"],"step_count":2} Oct 28 05:16:37.435265 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434034Z","caller":"traceutil/trace.go:171","msg":"trace[915455154] transaction","detail":"{read_only:false; response_revision:327; number_of_response:1; }","duration":"266.433247ms","start":"2025-10-28T05:16:37.167588Z","end":"2025-10-28T05:16:37.434021Z","steps":["trace[915455154] 'process raft request' (duration: 266.371932ms)"],"step_count":1} Oct 28 05:16:37.435265 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434121Z","caller":"traceutil/trace.go:171","msg":"trace[1270011435] transaction","detail":"{read_only:false; response_revision:326; number_of_response:1; }","duration":"285.354952ms","start":"2025-10-28T05:16:37.148760Z","end":"2025-10-28T05:16:37.434115Z","steps":["trace[1270011435] 'process raft request' (duration: 285.172209ms)"],"step_count":1} Oct 28 05:16:37.435265 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434096Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.061594Z","time spent":"372.428924ms","remote":"10.0.0.79:54194","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":673,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.435265 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434257Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"427.458895ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/legacy-service-account-token-cleaner\" limit:1 ","response":"range_response_count:1 size:238"} Oct 28 05:16:37.435410 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434288Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"477.431014ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/certificate-controller\" limit:1 ","response":"range_response_count:1 size:209"} Oct 28 05:16:37.435410 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434305Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"277.623003ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/clusterrole-aggregation-controller\" limit:1 ","response":"range_response_count:1 size:234"} Oct 28 05:16:37.435410 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434323Z","caller":"traceutil/trace.go:171","msg":"trace[828359554] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/certificate-controller; range_end:; response_count:1; response_revision:327; }","duration":"477.464857ms","start":"2025-10-28T05:16:36.956852Z","end":"2025-10-28T05:16:37.434317Z","steps":["trace[828359554] 'agreement among raft nodes before linearized reading' (duration: 477.42406ms)"],"step_count":1} Oct 28 05:16:37.435410 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434292Z","caller":"traceutil/trace.go:171","msg":"trace[911758681] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/legacy-service-account-token-cleaner; range_end:; response_count:1; response_revision:327; }","duration":"427.495233ms","start":"2025-10-28T05:16:37.006790Z","end":"2025-10-28T05:16:37.434285Z","steps":["trace[911758681] 'agreement among raft nodes before linearized reading' (duration: 427.437996ms)"],"step_count":1} Oct 28 05:16:37.435526 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434328Z","caller":"traceutil/trace.go:171","msg":"trace[1112619830] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/clusterrole-aggregation-controller; range_end:; response_count:1; response_revision:327; }","duration":"277.647148ms","start":"2025-10-28T05:16:37.156675Z","end":"2025-10-28T05:16:37.434322Z","steps":["trace[1112619830] 'agreement among raft nodes before linearized reading' (duration: 277.607374ms)"],"step_count":1} Oct 28 05:16:37.435526 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434343Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:36.956842Z","time spent":"477.494383ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":1,"response size":233,"request content":"key:\"/registry/serviceaccounts/kube-system/certificate-controller\" limit:1 "} Oct 28 05:16:37.435526 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434349Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.006780Z","time spent":"427.558632ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":78,"response count":1,"response size":262,"request content":"key:\"/registry/serviceaccounts/kube-system/legacy-service-account-token-cleaner\" limit:1 "} Oct 28 05:16:37.435526 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434281Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"327.369047ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/root-ca-cert-publisher\" limit:1 ","response":"range_response_count:1 size:209"} Oct 28 05:16:37.435526 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434263Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"377.528656ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/daemon-set-controller\" limit:1 ","response":"range_response_count:1 size:207"} Oct 28 05:16:37.435634 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434421Z","caller":"traceutil/trace.go:171","msg":"trace[545888235] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/root-ca-cert-publisher; range_end:; response_count:1; response_revision:327; }","duration":"327.57324ms","start":"2025-10-28T05:16:37.106835Z","end":"2025-10-28T05:16:37.434408Z","steps":["trace[545888235] 'agreement among raft nodes before linearized reading' (duration: 327.245805ms)"],"step_count":1} Oct 28 05:16:37.435634 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434542Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.106807Z","time spent":"327.720376ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":1,"response size":233,"request content":"key:\"/registry/serviceaccounts/kube-system/root-ca-cert-publisher\" limit:1 "} Oct 28 05:16:37.435634 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.434493Z","caller":"traceutil/trace.go:171","msg":"trace[1016039161] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/daemon-set-controller; range_end:; response_count:1; response_revision:327; }","duration":"377.761363ms","start":"2025-10-28T05:16:37.056725Z","end":"2025-10-28T05:16:37.434486Z","steps":["trace[1016039161] 'agreement among raft nodes before linearized reading' (duration: 377.49904ms)"],"step_count":1} Oct 28 05:16:37.435634 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.434633Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.056699Z","time spent":"377.92471ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":63,"response count":1,"response size":231,"request content":"key:\"/registry/serviceaccounts/kube-system/daemon-set-controller\" limit:1 "} Oct 28 05:16:37.774646 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774021Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"203.480028ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Oct 28 05:16:37.774646 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.774082Z","caller":"traceutil/trace.go:171","msg":"trace[1164323546] linearizableReadLoop","detail":"{readStateIndex:338; appliedIndex:337; }","duration":"340.067503ms","start":"2025-10-28T05:16:37.434006Z","end":"2025-10-28T05:16:37.774074Z","steps":["trace[1164323546] 'read index received' (duration: 136.580662ms)","trace[1164323546] 'applied index is now lower than readState.Index' (duration: 203.48611ms)"],"step_count":2} Oct 28 05:16:37.774646 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.774120Z","caller":"traceutil/trace.go:171","msg":"trace[1343423341] transaction","detail":"{read_only:false; response_revision:328; number_of_response:1; }","duration":"584.926314ms","start":"2025-10-28T05:16:37.189189Z","end":"2025-10-28T05:16:37.774116Z","steps":["trace[1343423341] 'process raft request' (duration: 381.319567ms)","trace[1343423341] 'compare' (duration: 203.360865ms)"],"step_count":2} Oct 28 05:16:37.774646 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774145Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.189176Z","time spent":"584.957413ms","remote":"10.0.0.79:54004","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":697,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:37.775027 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774214Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"566.760351ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/endpointslice-controller\" limit:1 ","response":"range_response_count:1 size:214"} Oct 28 05:16:37.775027 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.774232Z","caller":"traceutil/trace.go:171","msg":"trace[1132700400] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/endpointslice-controller; range_end:; response_count:1; response_revision:328; }","duration":"566.780107ms","start":"2025-10-28T05:16:37.207447Z","end":"2025-10-28T05:16:37.774227Z","steps":["trace[1132700400] 'agreement among raft nodes before linearized reading' (duration: 566.73374ms)"],"step_count":1} Oct 28 05:16:37.775027 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774246Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.207436Z","time spent":"566.805715ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":66,"response count":1,"response size":238,"request content":"key:\"/registry/serviceaccounts/kube-system/endpointslice-controller\" limit:1 "} Oct 28 05:16:37.775027 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774253Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"467.576476ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/deployment-controller\" limit:1 ","response":"range_response_count:1 size:207"} Oct 28 05:16:37.775027 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774259Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"516.917215ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/bootstrap-signer\" limit:1 ","response":"range_response_count:1 size:197"} Oct 28 05:16:37.775374 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.774306Z","caller":"traceutil/trace.go:171","msg":"trace[617656259] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/deployment-controller; range_end:; response_count:1; response_revision:328; }","duration":"467.634815ms","start":"2025-10-28T05:16:37.306657Z","end":"2025-10-28T05:16:37.774292Z","steps":["trace[617656259] 'agreement among raft nodes before linearized reading' (duration: 467.54141ms)"],"step_count":1} Oct 28 05:16:37.775374 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774337Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.306642Z","time spent":"467.687043ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":63,"response count":1,"response size":231,"request content":"key:\"/registry/serviceaccounts/kube-system/deployment-controller\" limit:1 "} Oct 28 05:16:37.775374 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.774333Z","caller":"traceutil/trace.go:171","msg":"trace[2041868817] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/bootstrap-signer; range_end:; response_count:1; response_revision:328; }","duration":"516.980003ms","start":"2025-10-28T05:16:37.257331Z","end":"2025-10-28T05:16:37.774311Z","steps":["trace[2041868817] 'agreement among raft nodes before linearized reading' (duration: 516.85571ms)"],"step_count":1} Oct 28 05:16:37.775374 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.774368Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.257315Z","time spent":"517.042551ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Range","request count":0,"request size":58,"response count":1,"response size":221,"request content":"key:\"/registry/serviceaccounts/kube-system/bootstrap-signer\" limit:1 "} Oct 28 05:16:37.781711 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781070Z","caller":"traceutil/trace.go:171","msg":"trace[1078649446] transaction","detail":"{read_only:false; response_revision:329; number_of_response:1; }","duration":"342.335426ms","start":"2025-10-28T05:16:37.438728Z","end":"2025-10-28T05:16:37.781063Z","steps":["trace[1078649446] 'process raft request' (duration: 342.185685ms)"],"step_count":1} Oct 28 05:16:37.781711 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781135Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.438712Z","time spent":"342.39633ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":164,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:37.781886 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781266Z","caller":"traceutil/trace.go:171","msg":"trace[1653185441] transaction","detail":"{read_only:false; response_revision:330; number_of_response:1; }","duration":"341.706635ms","start":"2025-10-28T05:16:37.439535Z","end":"2025-10-28T05:16:37.781242Z","steps":["trace[1653185441] 'process raft request' (duration: 341.490228ms)"],"step_count":1} Oct 28 05:16:37.781886 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781286Z","caller":"traceutil/trace.go:171","msg":"trace[145028245] transaction","detail":"{read_only:false; response_revision:331; number_of_response:1; }","duration":"339.992434ms","start":"2025-10-28T05:16:37.441288Z","end":"2025-10-28T05:16:37.781281Z","steps":["trace[145028245] 'process raft request' (duration: 339.766059ms)"],"step_count":1} Oct 28 05:16:37.781886 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781296Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.439528Z","time spent":"341.756748ms","remote":"10.0.0.79:53902","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1723,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:37.781886 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781244Z","caller":"traceutil/trace.go:171","msg":"trace[1597810417] transaction","detail":"{read_only:false; response_revision:334; number_of_response:1; }","duration":"338.9686ms","start":"2025-10-28T05:16:37.442258Z","end":"2025-10-28T05:16:37.781227Z","steps":["trace[1597810417] 'process raft request' (duration: 338.918346ms)"],"step_count":1} Oct 28 05:16:37.782137 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781353Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.442251Z","time spent":"339.090369ms","remote":"10.0.0.79:54642","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2102,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:37.782137 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781407Z","caller":"traceutil/trace.go:171","msg":"trace[811741570] transaction","detail":"{read_only:false; response_revision:332; number_of_response:1; }","duration":"340.027701ms","start":"2025-10-28T05:16:37.441367Z","end":"2025-10-28T05:16:37.781395Z","steps":["trace[811741570] 'process raft request' (duration: 339.757833ms)"],"step_count":1} Oct 28 05:16:37.782713 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781370Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.441281Z","time spent":"340.029894ms","remote":"10.0.0.79:54356","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2194,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.782713 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781368Z","caller":"traceutil/trace.go:171","msg":"trace[1872437365] transaction","detail":"{read_only:false; response_revision:333; number_of_response:1; }","duration":"339.819429ms","start":"2025-10-28T05:16:37.441537Z","end":"2025-10-28T05:16:37.781356Z","steps":["trace[1872437365] 'process raft request' (duration: 339.613843ms)"],"step_count":1} Oct 28 05:16:37.782713 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781714Z","caller":"traceutil/trace.go:171","msg":"trace[1670769200] transaction","detail":"{read_only:false; response_revision:336; number_of_response:1; }","duration":"339.365036ms","start":"2025-10-28T05:16:37.442343Z","end":"2025-10-28T05:16:37.781708Z","steps":["trace[1670769200] 'process raft request' (duration: 339.300073ms)"],"step_count":1} Oct 28 05:16:37.782713 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781751Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.442335Z","time spent":"339.394561ms","remote":"10.0.0.79:54170","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1377,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.782876 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781753Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.441529Z","time spent":"340.199704ms","remote":"10.0.0.79:54356","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":899,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.782876 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.781790Z","caller":"traceutil/trace.go:171","msg":"trace[677820396] transaction","detail":"{read_only:false; response_revision:335; number_of_response:1; }","duration":"339.478638ms","start":"2025-10-28T05:16:37.442301Z","end":"2025-10-28T05:16:37.781780Z","steps":["trace[677820396] 'process raft request' (duration: 338.898909ms)"],"step_count":1} Oct 28 05:16:37.782876 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.781903Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.442293Z","time spent":"339.596249ms","remote":"10.0.0.79:54642","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":5691,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:37.782968 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.782316Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.441348Z","time spent":"340.097131ms","remote":"10.0.0.79:54356","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2299,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:37.785428 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.785143Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"343.684051ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/configmaps/kube-system/kube-apiserver-legacy-service-account-token-tracking\" limit:1 ","response":"range_response_count:1 size:370"} Oct 28 05:16:37.785428 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:37.785192Z","caller":"traceutil/trace.go:171","msg":"trace[657052058] range","detail":"{range_begin:/registry/configmaps/kube-system/kube-apiserver-legacy-service-account-token-tracking; range_end:; response_count:1; response_revision:337; }","duration":"343.737573ms","start":"2025-10-28T05:16:37.441443Z","end":"2025-10-28T05:16:37.785180Z","steps":["trace[657052058] 'agreement among raft nodes before linearized reading' (duration: 343.654636ms)"],"step_count":1} Oct 28 05:16:37.785428 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:37.785299Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.441435Z","time spent":"343.774141ms","remote":"10.0.0.79:53902","response type":"/etcdserverpb.KV/Range","request count":0,"request size":89,"response count":1,"response size":394,"request content":"key:\"/registry/configmaps/kube-system/kube-apiserver-legacy-service-account-token-tracking\" limit:1 "} Oct 28 05:16:38.176973 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176240Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.156858ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Oct 28 05:16:38.176973 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176411Z","caller":"traceutil/trace.go:171","msg":"trace[73496788] transaction","detail":"{read_only:false; response_revision:340; number_of_response:1; }","duration":"385.681776ms","start":"2025-10-28T05:16:37.790708Z","end":"2025-10-28T05:16:38.176389Z","steps":["trace[73496788] 'process raft request' (duration: 385.598548ms)"],"step_count":1} Oct 28 05:16:38.177500 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176567Z","caller":"traceutil/trace.go:171","msg":"trace[200953265] linearizableReadLoop","detail":"{readStateIndex:349; appliedIndex:347; }","duration":"387.220697ms","start":"2025-10-28T05:16:37.789336Z","end":"2025-10-28T05:16:38.176557Z","steps":["trace[200953265] 'read index received' (duration: 27.349741ms)","trace[200953265] 'applied index is now lower than readState.Index' (duration: 359.869503ms)"],"step_count":2} Oct 28 05:16:38.177500 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176590Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.790687Z","time spent":"385.857485ms","remote":"10.0.0.79:54080","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":164,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:38.177500 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176631Z","caller":"traceutil/trace.go:171","msg":"trace[2115089005] transaction","detail":"{read_only:false; response_revision:342; number_of_response:1; }","duration":"381.412293ms","start":"2025-10-28T05:16:37.795213Z","end":"2025-10-28T05:16:38.176625Z","steps":["trace[2115089005] 'process raft request' (duration: 381.14412ms)"],"step_count":1} Oct 28 05:16:38.177500 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176661Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.795204Z","time spent":"381.441919ms","remote":"10.0.0.79:53902","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1733,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:38.177666 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176647Z","caller":"traceutil/trace.go:171","msg":"trace[148317210] transaction","detail":"{read_only:false; response_revision:341; number_of_response:1; }","duration":"382.205774ms","start":"2025-10-28T05:16:37.794409Z","end":"2025-10-28T05:16:38.176615Z","steps":["trace[148317210] 'process raft request' (duration: 381.927942ms)"],"step_count":1} Oct 28 05:16:38.177666 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176695Z","caller":"traceutil/trace.go:171","msg":"trace[1736157500] transaction","detail":"{read_only:false; response_revision:339; number_of_response:1; }","duration":"389.868613ms","start":"2025-10-28T05:16:37.786782Z","end":"2025-10-28T05:16:38.176651Z","steps":["trace[1736157500] 'process raft request' (duration: 270.265396ms)","trace[1736157500] 'compare' (duration: 119.062201ms)"],"step_count":2} Oct 28 05:16:38.177666 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176730Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.786748Z","time spent":"389.965895ms","remote":"10.0.0.79:54200","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1045,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:38.177666 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176736Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.794401Z","time spent":"382.296675ms","remote":"10.0.0.79:54620","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":3924,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:38.177787 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176891Z","caller":"traceutil/trace.go:171","msg":"trace[80043469] transaction","detail":"{read_only:false; response_revision:346; number_of_response:1; }","duration":"373.200132ms","start":"2025-10-28T05:16:37.803684Z","end":"2025-10-28T05:16:38.176884Z","steps":["trace[80043469] 'process raft request' (duration: 372.850225ms)"],"step_count":1} Oct 28 05:16:38.177787 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176891Z","caller":"traceutil/trace.go:171","msg":"trace[1039752052] transaction","detail":"{read_only:false; response_revision:345; number_of_response:1; }","duration":"376.377762ms","start":"2025-10-28T05:16:37.800504Z","end":"2025-10-28T05:16:38.176882Z","steps":["trace[1039752052] 'process raft request' (duration: 375.999181ms)"],"step_count":1} Oct 28 05:16:38.177787 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176930Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.803663Z","time spent":"373.244726ms","remote":"10.0.0.79:54356","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":3669,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:38.177787 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176947Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.800498Z","time spent":"376.417166ms","remote":"10.0.0.79:54170","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2393,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:38.177889 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.176962Z","caller":"traceutil/trace.go:171","msg":"trace[1002977069] transaction","detail":"{read_only:false; response_revision:344; number_of_response:1; }","duration":"376.833771ms","start":"2025-10-28T05:16:37.800119Z","end":"2025-10-28T05:16:38.176953Z","steps":["trace[1002977069] 'process raft request' (duration: 376.320997ms)"],"step_count":1} Oct 28 05:16:38.177889 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.176991Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"387.65335ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/kube-controller-manager-localhost.18728fdeab46b35d\" limit:1 ","response":"range_response_count:1 size:844"} Oct 28 05:16:38.177889 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.177007Z","caller":"traceutil/trace.go:171","msg":"trace[1449385404] range","detail":"{range_begin:/registry/events/kube-system/kube-controller-manager-localhost.18728fdeab46b35d; range_end:; response_count:1; response_revision:346; }","duration":"387.668278ms","start":"2025-10-28T05:16:37.789333Z","end":"2025-10-28T05:16:38.177001Z","steps":["trace[1449385404] 'agreement among raft nodes before linearized reading' (duration: 387.622643ms)"],"step_count":1} Oct 28 05:16:38.177889 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177008Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.800113Z","time spent":"376.871742ms","remote":"10.0.0.79:54356","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2372,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:16:38.177979 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177021Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.789323Z","time spent":"387.693956ms","remote":"10.0.0.79:53852","response type":"/etcdserverpb.KV/Range","request count":0,"request size":83,"response count":1,"response size":868,"request content":"key:\"/registry/events/kube-system/kube-controller-manager-localhost.18728fdeab46b35d\" limit:1 "} Oct 28 05:16:38.177979 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177060Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"380.958721ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/kube-controller-manager-localhost\" limit:1 ","response":"range_response_count:1 size:6805"} Oct 28 05:16:38.177979 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.177067Z","caller":"traceutil/trace.go:171","msg":"trace[1517421852] transaction","detail":"{read_only:false; response_revision:343; number_of_response:1; }","duration":"380.682742ms","start":"2025-10-28T05:16:37.796378Z","end":"2025-10-28T05:16:38.177060Z","steps":["trace[1517421852] 'process raft request' (duration: 380.006281ms)"],"step_count":1} Oct 28 05:16:38.177979 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177077Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"378.294014ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/limitranges\" limit:1 ","response":"range_response_count:0 size:5"} Oct 28 05:16:38.177979 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.177077Z","caller":"traceutil/trace.go:171","msg":"trace[1487553857] range","detail":"{range_begin:/registry/pods/kube-system/kube-controller-manager-localhost; range_end:; response_count:1; response_revision:346; }","duration":"380.974721ms","start":"2025-10-28T05:16:37.796096Z","end":"2025-10-28T05:16:38.177071Z","steps":["trace[1487553857] 'agreement among raft nodes before linearized reading' (duration: 380.939244ms)"],"step_count":1} Oct 28 05:16:38.178088 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.177090Z","caller":"traceutil/trace.go:171","msg":"trace[1283306170] range","detail":"{range_begin:/registry/limitranges; range_end:; response_count:0; response_revision:346; }","duration":"378.305795ms","start":"2025-10-28T05:16:37.798780Z","end":"2025-10-28T05:16:38.177086Z","steps":["trace[1283306170] 'agreement among raft nodes before linearized reading' (duration: 378.288784ms)"],"step_count":1} Oct 28 05:16:38.178088 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177103Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.796091Z","time spent":"381.007943ms","remote":"10.0.0.79:54046","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":1,"response size":6829,"request content":"key:\"/registry/pods/kube-system/kube-controller-manager-localhost\" limit:1 "} Oct 28 05:16:38.178088 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177103Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.798775Z","time spent":"378.325162ms","remote":"10.0.0.79:53952","response type":"/etcdserverpb.KV/Range","request count":0,"request size":25,"response count":0,"response size":29,"request content":"key:\"/registry/limitranges\" limit:1 "} Oct 28 05:16:38.178088 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.177105Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:16:37.796369Z","time spent":"380.717217ms","remote":"10.0.0.79:54046","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":3359,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:16:38.450550 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.449955Z","caller":"traceutil/trace.go:171","msg":"trace[1729814553] transaction","detail":"{read_only:false; response_revision:349; number_of_response:1; }","duration":"268.640253ms","start":"2025-10-28T05:16:38.181290Z","end":"2025-10-28T05:16:38.449930Z","steps":["trace[1729814553] 'process raft request' (duration: 268.205236ms)"],"step_count":1} Oct 28 05:16:38.450550 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450204Z","caller":"traceutil/trace.go:171","msg":"trace[1362505013] transaction","detail":"{read_only:false; response_revision:348; number_of_response:1; }","duration":"270.218658ms","start":"2025-10-28T05:16:38.179977Z","end":"2025-10-28T05:16:38.450196Z","steps":["trace[1362505013] 'process raft request' (duration: 247.570718ms)","trace[1362505013] 'compare' (duration: 21.79125ms)"],"step_count":2} Oct 28 05:16:38.450550 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450267Z","caller":"traceutil/trace.go:171","msg":"trace[731412225] transaction","detail":"{read_only:false; response_revision:350; number_of_response:1; }","duration":"267.557178ms","start":"2025-10-28T05:16:38.182701Z","end":"2025-10-28T05:16:38.450258Z","steps":["trace[731412225] 'process raft request' (duration: 266.834801ms)"],"step_count":1} Oct 28 05:16:38.451485 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450582Z","caller":"traceutil/trace.go:171","msg":"trace[1627924360] linearizableReadLoop","detail":"{readStateIndex:360; appliedIndex:356; }","duration":"267.443664ms","start":"2025-10-28T05:16:38.183084Z","end":"2025-10-28T05:16:38.450528Z","steps":["trace[1627924360] 'read index received' (duration: 89.251643ms)","trace[1627924360] 'applied index is now lower than readState.Index' (duration: 178.19153ms)"],"step_count":2} Oct 28 05:16:38.451485 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450691Z","caller":"traceutil/trace.go:171","msg":"trace[2011248649] transaction","detail":"{read_only:false; response_revision:351; number_of_response:1; }","duration":"267.584448ms","start":"2025-10-28T05:16:38.183084Z","end":"2025-10-28T05:16:38.450669Z","steps":["trace[2011248649] 'process raft request' (duration: 266.758857ms)"],"step_count":1} Oct 28 05:16:38.451485 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450726Z","caller":"traceutil/trace.go:171","msg":"trace[809313258] transaction","detail":"{read_only:false; response_revision:354; number_of_response:1; }","duration":"265.873746ms","start":"2025-10-28T05:16:38.184844Z","end":"2025-10-28T05:16:38.450718Z","steps":["trace[809313258] 'process raft request' (duration: 265.523808ms)"],"step_count":1} Oct 28 05:16:38.451485 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450857Z","caller":"traceutil/trace.go:171","msg":"trace[1728957510] transaction","detail":"{read_only:false; response_revision:353; number_of_response:1; }","duration":"267.277744ms","start":"2025-10-28T05:16:38.183574Z","end":"2025-10-28T05:16:38.450851Z","steps":["trace[1728957510] 'process raft request' (duration: 266.757476ms)"],"step_count":1} Oct 28 05:16:38.451485 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.451077Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"267.976545ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/replicaset-controller\" limit:1 ","response":"range_response_count:1 size:207"} Oct 28 05:16:38.451810 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:38.451090Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"264.904523ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/edit\" limit:1 ","response":"range_response_count:1 size:3683"} Oct 28 05:16:38.451810 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.451103Z","caller":"traceutil/trace.go:171","msg":"trace[1601654483] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/replicaset-controller; range_end:; response_count:1; response_revision:356; }","duration":"268.013605ms","start":"2025-10-28T05:16:38.183081Z","end":"2025-10-28T05:16:38.451094Z","steps":["trace[1601654483] 'agreement among raft nodes before linearized reading' (duration: 267.954824ms)"],"step_count":1} Oct 28 05:16:38.451810 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.451119Z","caller":"traceutil/trace.go:171","msg":"trace[746688796] range","detail":"{range_begin:/registry/clusterroles/edit; range_end:; response_count:1; response_revision:356; }","duration":"264.94537ms","start":"2025-10-28T05:16:38.186166Z","end":"2025-10-28T05:16:38.451111Z","steps":["trace[746688796] 'agreement among raft nodes before linearized reading' (duration: 264.879958ms)"],"step_count":1} Oct 28 05:16:38.451810 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.451149Z","caller":"traceutil/trace.go:171","msg":"trace[1966100062] transaction","detail":"{read_only:false; response_revision:355; number_of_response:1; }","duration":"265.742379ms","start":"2025-10-28T05:16:38.185401Z","end":"2025-10-28T05:16:38.451144Z","steps":["trace[1966100062] 'process raft request' (duration: 265.023548ms)"],"step_count":1} Oct 28 05:16:38.451810 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.450760Z","caller":"traceutil/trace.go:171","msg":"trace[418834211] transaction","detail":"{read_only:false; response_revision:352; number_of_response:1; }","duration":"267.190048ms","start":"2025-10-28T05:16:38.183564Z","end":"2025-10-28T05:16:38.450754Z","steps":["trace[418834211] 'process raft request' (duration: 266.306738ms)"],"step_count":1} Oct 28 05:16:38.452009 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:38.451317Z","caller":"traceutil/trace.go:171","msg":"trace[600659089] transaction","detail":"{read_only:false; response_revision:356; number_of_response:1; }","duration":"265.319844ms","start":"2025-10-28T05:16:38.185989Z","end":"2025-10-28T05:16:38.451309Z","steps":["trace[600659089] 'process raft request' (duration: 264.462073ms)"],"step_count":1} Oct 28 05:16:39.508607 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:39.508245Z","caller":"traceutil/trace.go:171","msg":"trace[428739511] transaction","detail":"{read_only:false; response_revision:396; number_of_response:1; }","duration":"100.265816ms","start":"2025-10-28T05:16:39.407961Z","end":"2025-10-28T05:16:39.508227Z","steps":["trace[428739511] 'process raft request' (duration: 100.173051ms)"],"step_count":1} Oct 28 05:16:41.915340 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:41.914956Z","caller":"traceutil/trace.go:171","msg":"trace[1368418786] transaction","detail":"{read_only:false; response_revision:409; number_of_response:1; }","duration":"120.285688ms","start":"2025-10-28T05:16:41.794655Z","end":"2025-10-28T05:16:41.914940Z","steps":["trace[1368418786] 'process raft request' (duration: 120.196231ms)"],"step_count":1} Oct 28 05:16:56.542636 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:56.542157Z","caller":"traceutil/trace.go:171","msg":"trace[980221054] linearizableReadLoop","detail":"{readStateIndex:480; appliedIndex:479; }","duration":"100.645825ms","start":"2025-10-28T05:16:56.441491Z","end":"2025-10-28T05:16:56.542137Z","steps":["trace[980221054] 'read index received' (duration: 100.028276ms)","trace[980221054] 'applied index is now lower than readState.Index' (duration: 616.828µs)"],"step_count":2} Oct 28 05:16:56.542636 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:56.542190Z","caller":"traceutil/trace.go:171","msg":"trace[1498326538] transaction","detail":"{read_only:false; response_revision:465; number_of_response:1; }","duration":"269.800462ms","start":"2025-10-28T05:16:56.272377Z","end":"2025-10-28T05:16:56.542177Z","steps":["trace[1498326538] 'process raft request' (duration: 269.138189ms)"],"step_count":1} Oct 28 05:16:56.543307 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:56.542268Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"100.760801ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/coredns-66bc5c9577-6lhkn\" limit:1 ","response":"range_response_count:1 size:5536"} Oct 28 05:16:56.543307 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:56.542296Z","caller":"traceutil/trace.go:171","msg":"trace[1827938123] range","detail":"{range_begin:/registry/pods/kube-system/coredns-66bc5c9577-6lhkn; range_end:; response_count:1; response_revision:465; }","duration":"100.803541ms","start":"2025-10-28T05:16:56.441486Z","end":"2025-10-28T05:16:56.542289Z","steps":["trace[1827938123] 'agreement among raft nodes before linearized reading' (duration: 100.739771ms)"],"step_count":1} Oct 28 05:16:56.543307 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:56.542307Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"100.800735ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/coredns-66bc5c9577-6lhkn.18728fe1d2116f1c\" limit:1 ","response":"range_response_count:1 size:824"} Oct 28 05:16:56.543307 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:56.542328Z","caller":"traceutil/trace.go:171","msg":"trace[338854345] range","detail":"{range_begin:/registry/events/kube-system/coredns-66bc5c9577-6lhkn.18728fe1d2116f1c; range_end:; response_count:1; response_revision:465; }","duration":"100.820803ms","start":"2025-10-28T05:16:56.441499Z","end":"2025-10-28T05:16:56.542320Z","steps":["trace[338854345] 'agreement among raft nodes before linearized reading' (duration: 100.785747ms)"],"step_count":1} Oct 28 05:16:59.008238 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:16:59.007849Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"121.318159ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Oct 28 05:16:59.008238 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:16:59.007937Z","caller":"traceutil/trace.go:171","msg":"trace[622103310] transaction","detail":"{read_only:false; response_revision:510; number_of_response:1; }","duration":"191.05612ms","start":"2025-10-28T05:16:58.816866Z","end":"2025-10-28T05:16:59.007922Z","steps":["trace[622103310] 'process raft request' (duration: 69.616516ms)","trace[622103310] 'compare' (duration: 121.238705ms)"],"step_count":2} Oct 28 05:17:01.682075 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:01.681698Z","caller":"traceutil/trace.go:171","msg":"trace[1518503144] transaction","detail":"{read_only:false; response_revision:535; number_of_response:1; }","duration":"159.174753ms","start":"2025-10-28T05:17:01.522500Z","end":"2025-10-28T05:17:01.681675Z","steps":["trace[1518503144] 'process raft request' (duration: 82.271273ms)","trace[1518503144] 'compare' (duration: 76.822894ms)"],"step_count":2} Oct 28 05:17:30.056675 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.056105Z","caller":"traceutil/trace.go:171","msg":"trace[1540535065] transaction","detail":"{read_only:false; response_revision:635; number_of_response:1; }","duration":"165.424631ms","start":"2025-10-28T05:17:29.890657Z","end":"2025-10-28T05:17:30.056082Z","steps":["trace[1540535065] 'process raft request' (duration: 67.131984ms)","trace[1540535065] 'compare' (duration: 98.156398ms)"],"step_count":2} Oct 28 05:17:30.430481 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:30.429862Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"248.534225ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Oct 28 05:17:30.430481 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.429953Z","caller":"traceutil/trace.go:171","msg":"trace[1381505448] transaction","detail":"{read_only:false; response_revision:638; number_of_response:1; }","duration":"310.407726ms","start":"2025-10-28T05:17:30.119534Z","end":"2025-10-28T05:17:30.429942Z","steps":["trace[1381505448] 'process raft request' (duration: 61.738343ms)","trace[1381505448] 'compare' (duration: 248.438884ms)"],"step_count":2} Oct 28 05:17:30.430481 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:30.429988Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:17:30.119515Z","time spent":"310.456961ms","remote":"10.0.0.79:54194","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 28 05:17:30.434338 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.433973Z","caller":"traceutil/trace.go:171","msg":"trace[704496195] linearizableReadLoop","detail":"{readStateIndex:662; appliedIndex:661; }","duration":"215.46473ms","start":"2025-10-28T05:17:30.218498Z","end":"2025-10-28T05:17:30.433963Z","steps":["trace[704496195] 'read index received' (duration: 215.382023ms)","trace[704496195] 'applied index is now lower than readState.Index' (duration: 81.855µs)"],"step_count":2} Oct 28 05:17:30.434338 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.434036Z","caller":"traceutil/trace.go:171","msg":"trace[369116619] transaction","detail":"{read_only:false; response_revision:639; number_of_response:1; }","duration":"282.569717ms","start":"2025-10-28T05:17:30.151443Z","end":"2025-10-28T05:17:30.434013Z","steps":["trace[369116619] 'process raft request' (duration: 282.478503ms)"],"step_count":1} Oct 28 05:17:30.434338 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:30.434088Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"188.006184ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/networkpolicies\" limit:1 ","response":"range_response_count:0 size:5"} Oct 28 05:17:30.434338 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.434103Z","caller":"traceutil/trace.go:171","msg":"trace[123451999] range","detail":"{range_begin:/registry/networkpolicies; range_end:; response_count:0; response_revision:639; }","duration":"188.020771ms","start":"2025-10-28T05:17:30.246077Z","end":"2025-10-28T05:17:30.434098Z","steps":["trace[123451999] 'agreement among raft nodes before linearized reading' (duration: 188.003949ms)"],"step_count":1} Oct 28 05:17:30.434338 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:30.434063Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"215.561665ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 28 05:17:30.434515 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:30.434147Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"120.952916ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/resourcequotas\" limit:1 ","response":"range_response_count:0 size:5"} Oct 28 05:17:30.434515 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.434162Z","caller":"traceutil/trace.go:171","msg":"trace[1673404167] range","detail":"{range_begin:/registry/resourcequotas; range_end:; response_count:0; response_revision:639; }","duration":"120.966872ms","start":"2025-10-28T05:17:30.313191Z","end":"2025-10-28T05:17:30.434158Z","steps":["trace[1673404167] 'agreement among raft nodes before linearized reading' (duration: 120.946322ms)"],"step_count":1} Oct 28 05:17:30.434515 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.434171Z","caller":"traceutil/trace.go:171","msg":"trace[356183932] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:639; }","duration":"215.664751ms","start":"2025-10-28T05:17:30.218494Z","end":"2025-10-28T05:17:30.434159Z","steps":["trace[356183932] 'agreement among raft nodes before linearized reading' (duration: 215.527269ms)"],"step_count":1} Oct 28 05:17:30.681781 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:30.681275Z","caller":"traceutil/trace.go:171","msg":"trace[1243811510] transaction","detail":"{read_only:false; response_revision:643; number_of_response:1; }","duration":"152.332164ms","start":"2025-10-28T05:17:30.528924Z","end":"2025-10-28T05:17:30.681256Z","steps":["trace[1243811510] 'process raft request' (duration: 139.658586ms)","trace[1243811510] 'compare' (duration: 12.580932ms)"],"step_count":2} Oct 28 05:17:31.067212 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:31.066787Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"211.181905ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Oct 28 05:17:31.067212 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:31.066887Z","caller":"traceutil/trace.go:171","msg":"trace[211557842] transaction","detail":"{read_only:false; response_revision:644; number_of_response:1; }","duration":"534.423525ms","start":"2025-10-28T05:17:30.532446Z","end":"2025-10-28T05:17:31.066869Z","steps":["trace[211557842] 'process raft request' (duration: 323.112175ms)","trace[211557842] 'compare' (duration: 211.073348ms)"],"step_count":2} Oct 28 05:17:31.067212 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:31.066971Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-10-28T05:17:30.532437Z","time spent":"534.512454ms","remote":"10.0.0.79:54642","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2868,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 28 05:17:44.064202 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:44.063852Z","caller":"traceutil/trace.go:171","msg":"trace[684073611] transaction","detail":"{read_only:false; response_revision:701; number_of_response:1; }","duration":"131.645084ms","start":"2025-10-28T05:17:43.932193Z","end":"2025-10-28T05:17:44.063839Z","steps":["trace[684073611] 'process raft request' (duration: 131.558972ms)"],"step_count":1} Oct 28 05:17:44.339695 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:44.339205Z","caller":"traceutil/trace.go:171","msg":"trace[386024874] linearizableReadLoop","detail":"{readStateIndex:728; appliedIndex:727; }","duration":"109.302185ms","start":"2025-10-28T05:17:44.229881Z","end":"2025-10-28T05:17:44.339184Z","steps":["trace[386024874] 'read index received' (duration: 25.871963ms)","trace[386024874] 'applied index is now lower than readState.Index' (duration: 83.42937ms)"],"step_count":2} Oct 28 05:17:44.339695 etcd-wrapper[1920]: {"level":"warn","ts":"2025-10-28T05:17:44.339302Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"109.405751ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 28 05:17:44.339695 etcd-wrapper[1920]: {"level":"info","ts":"2025-10-28T05:17:44.339350Z","caller":"traceutil/trace.go:171","msg":"trace[1147367674] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:701; }","duration":"109.465174ms","start":"2025-10-28T05:17:44.229873Z","end":"2025-10-28T05:17:44.339339Z","steps":["trace[1147367674] 'agreement among raft nodes before linearized reading' (duration: 109.380012ms)"],"step_count":1}