Sep 12 05:53:17.829377 kernel: Linux version 6.12.46-flatcar (build@pony-truck.infra.kinvolk.io) (x86_64-cros-linux-gnu-gcc (Gentoo Hardened 14.3.0 p8) 14.3.0, GNU ld (Gentoo 2.44 p4) 2.44.0) #1 SMP PREEMPT_DYNAMIC Fri Sep 12 04:02:32 -00 2025 Sep 12 05:53:17.829408 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=d36684c42387dba16669740eb40ca6a094be0dfb03f64a303630b6ac6cfe48d3 Sep 12 05:53:17.829420 kernel: BIOS-provided physical RAM map: Sep 12 05:53:17.829429 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable Sep 12 05:53:17.829437 kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved Sep 12 05:53:17.829446 kernel: BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved Sep 12 05:53:17.829456 kernel: BIOS-e820: [mem 0x0000000000100000-0x000000009cfdbfff] usable Sep 12 05:53:17.829465 kernel: BIOS-e820: [mem 0x000000009cfdc000-0x000000009cffffff] reserved Sep 12 05:53:17.829479 kernel: BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved Sep 12 05:53:17.829487 kernel: BIOS-e820: [mem 0x00000000fed1c000-0x00000000fed1ffff] reserved Sep 12 05:53:17.829496 kernel: BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved Sep 12 05:53:17.829505 kernel: BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved Sep 12 05:53:17.829514 kernel: BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved Sep 12 05:53:17.829522 kernel: NX (Execute Disable) protection: active Sep 12 05:53:17.829536 kernel: APIC: Static calls initialized Sep 12 05:53:17.829545 kernel: SMBIOS 2.8 present. Sep 12 05:53:17.829557 kernel: DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 Sep 12 05:53:17.829567 kernel: DMI: Memory slots populated: 1/1 Sep 12 05:53:17.829576 kernel: Hypervisor detected: KVM Sep 12 05:53:17.829585 kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00 Sep 12 05:53:17.829595 kernel: kvm-clock: using sched offset of 4908310898 cycles Sep 12 05:53:17.829604 kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns Sep 12 05:53:17.829614 kernel: tsc: Detected 2794.748 MHz processor Sep 12 05:53:17.829624 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Sep 12 05:53:17.829637 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Sep 12 05:53:17.829646 kernel: last_pfn = 0x9cfdc max_arch_pfn = 0x400000000 Sep 12 05:53:17.829656 kernel: MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs Sep 12 05:53:17.829666 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Sep 12 05:53:17.829675 kernel: Using GB pages for direct mapping Sep 12 05:53:17.829685 kernel: ACPI: Early table checksum verification disabled Sep 12 05:53:17.829695 kernel: ACPI: RSDP 0x00000000000F59D0 000014 (v00 BOCHS ) Sep 12 05:53:17.829704 kernel: ACPI: RSDT 0x000000009CFE241A 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829716 kernel: ACPI: FACP 0x000000009CFE21FA 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829726 kernel: ACPI: DSDT 0x000000009CFE0040 0021BA (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829736 kernel: ACPI: FACS 0x000000009CFE0000 000040 Sep 12 05:53:17.829746 kernel: ACPI: APIC 0x000000009CFE22EE 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829755 kernel: ACPI: HPET 0x000000009CFE237E 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829765 kernel: ACPI: MCFG 0x000000009CFE23B6 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829775 kernel: ACPI: WAET 0x000000009CFE23F2 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) Sep 12 05:53:17.829784 kernel: ACPI: Reserving FACP table memory at [mem 0x9cfe21fa-0x9cfe22ed] Sep 12 05:53:17.829801 kernel: ACPI: Reserving DSDT table memory at [mem 0x9cfe0040-0x9cfe21f9] Sep 12 05:53:17.829811 kernel: ACPI: Reserving FACS table memory at [mem 0x9cfe0000-0x9cfe003f] Sep 12 05:53:17.829821 kernel: ACPI: Reserving APIC table memory at [mem 0x9cfe22ee-0x9cfe237d] Sep 12 05:53:17.829831 kernel: ACPI: Reserving HPET table memory at [mem 0x9cfe237e-0x9cfe23b5] Sep 12 05:53:17.829841 kernel: ACPI: Reserving MCFG table memory at [mem 0x9cfe23b6-0x9cfe23f1] Sep 12 05:53:17.829851 kernel: ACPI: Reserving WAET table memory at [mem 0x9cfe23f2-0x9cfe2419] Sep 12 05:53:17.829863 kernel: No NUMA configuration found Sep 12 05:53:17.829873 kernel: Faking a node at [mem 0x0000000000000000-0x000000009cfdbfff] Sep 12 05:53:17.829883 kernel: NODE_DATA(0) allocated [mem 0x9cfd4dc0-0x9cfdbfff] Sep 12 05:53:17.829893 kernel: Zone ranges: Sep 12 05:53:17.829903 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Sep 12 05:53:17.829912 kernel: DMA32 [mem 0x0000000001000000-0x000000009cfdbfff] Sep 12 05:53:17.829922 kernel: Normal empty Sep 12 05:53:17.829932 kernel: Device empty Sep 12 05:53:17.829942 kernel: Movable zone start for each node Sep 12 05:53:17.829952 kernel: Early memory node ranges Sep 12 05:53:17.829964 kernel: node 0: [mem 0x0000000000001000-0x000000000009efff] Sep 12 05:53:17.829974 kernel: node 0: [mem 0x0000000000100000-0x000000009cfdbfff] Sep 12 05:53:17.829984 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000009cfdbfff] Sep 12 05:53:17.829994 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Sep 12 05:53:17.830004 kernel: On node 0, zone DMA: 97 pages in unavailable ranges Sep 12 05:53:17.830014 kernel: On node 0, zone DMA32: 12324 pages in unavailable ranges Sep 12 05:53:17.830023 kernel: ACPI: PM-Timer IO Port: 0x608 Sep 12 05:53:17.830036 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Sep 12 05:53:17.830046 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Sep 12 05:53:17.830058 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Sep 12 05:53:17.830068 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Sep 12 05:53:17.830080 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Sep 12 05:53:17.830090 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Sep 12 05:53:17.830100 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Sep 12 05:53:17.830124 kernel: ACPI: Using ACPI (MADT) for SMP configuration information Sep 12 05:53:17.830135 kernel: ACPI: HPET id: 0x8086a201 base: 0xfed00000 Sep 12 05:53:17.830153 kernel: TSC deadline timer available Sep 12 05:53:17.830163 kernel: CPU topo: Max. logical packages: 1 Sep 12 05:53:17.830176 kernel: CPU topo: Max. logical dies: 1 Sep 12 05:53:17.830186 kernel: CPU topo: Max. dies per package: 1 Sep 12 05:53:17.830196 kernel: CPU topo: Max. threads per core: 1 Sep 12 05:53:17.830206 kernel: CPU topo: Num. cores per package: 4 Sep 12 05:53:17.830216 kernel: CPU topo: Num. threads per package: 4 Sep 12 05:53:17.830225 kernel: CPU topo: Allowing 4 present CPUs plus 0 hotplug CPUs Sep 12 05:53:17.830235 kernel: kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() Sep 12 05:53:17.830245 kernel: kvm-guest: KVM setup pv remote TLB flush Sep 12 05:53:17.830255 kernel: kvm-guest: setup PV sched yield Sep 12 05:53:17.830265 kernel: [mem 0xc0000000-0xfed1bfff] available for PCI devices Sep 12 05:53:17.830277 kernel: Booting paravirtualized kernel on KVM Sep 12 05:53:17.830287 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns Sep 12 05:53:17.830297 kernel: setup_percpu: NR_CPUS:512 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 Sep 12 05:53:17.830308 kernel: percpu: Embedded 60 pages/cpu s207832 r8192 d29736 u524288 Sep 12 05:53:17.830318 kernel: pcpu-alloc: s207832 r8192 d29736 u524288 alloc=1*2097152 Sep 12 05:53:17.830327 kernel: pcpu-alloc: [0] 0 1 2 3 Sep 12 05:53:17.830337 kernel: kvm-guest: PV spinlocks enabled Sep 12 05:53:17.830347 kernel: PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) Sep 12 05:53:17.830358 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=d36684c42387dba16669740eb40ca6a094be0dfb03f64a303630b6ac6cfe48d3 Sep 12 05:53:17.830371 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. Sep 12 05:53:17.830381 kernel: random: crng init done Sep 12 05:53:17.830391 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Sep 12 05:53:17.830401 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Sep 12 05:53:17.830411 kernel: Fallback order for Node 0: 0 Sep 12 05:53:17.830421 kernel: Built 1 zonelists, mobility grouping on. Total pages: 642938 Sep 12 05:53:17.830431 kernel: Policy zone: DMA32 Sep 12 05:53:17.830443 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Sep 12 05:53:17.830457 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Sep 12 05:53:17.830468 kernel: ftrace: allocating 40123 entries in 157 pages Sep 12 05:53:17.830478 kernel: ftrace: allocated 157 pages with 5 groups Sep 12 05:53:17.830488 kernel: Dynamic Preempt: voluntary Sep 12 05:53:17.830498 kernel: rcu: Preemptible hierarchical RCU implementation. Sep 12 05:53:17.830508 kernel: rcu: RCU event tracing is enabled. Sep 12 05:53:17.830519 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Sep 12 05:53:17.830529 kernel: Trampoline variant of Tasks RCU enabled. Sep 12 05:53:17.830542 kernel: Rude variant of Tasks RCU enabled. Sep 12 05:53:17.830554 kernel: Tracing variant of Tasks RCU enabled. Sep 12 05:53:17.830564 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Sep 12 05:53:17.830574 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Sep 12 05:53:17.830584 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Sep 12 05:53:17.830594 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Sep 12 05:53:17.830604 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Sep 12 05:53:17.830614 kernel: NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16 Sep 12 05:53:17.830625 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Sep 12 05:53:17.830645 kernel: Console: colour VGA+ 80x25 Sep 12 05:53:17.830655 kernel: printk: legacy console [ttyS0] enabled Sep 12 05:53:17.830666 kernel: ACPI: Core revision 20240827 Sep 12 05:53:17.830676 kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns Sep 12 05:53:17.830689 kernel: APIC: Switch to symmetric I/O mode setup Sep 12 05:53:17.830699 kernel: x2apic enabled Sep 12 05:53:17.830710 kernel: APIC: Switched APIC routing to: physical x2apic Sep 12 05:53:17.830722 kernel: kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() Sep 12 05:53:17.830733 kernel: kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() Sep 12 05:53:17.830746 kernel: kvm-guest: setup PV IPIs Sep 12 05:53:17.830756 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Sep 12 05:53:17.830767 kernel: clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x2848df6a9de, max_idle_ns: 440795280912 ns Sep 12 05:53:17.830778 kernel: Calibrating delay loop (skipped) preset value.. 5589.49 BogoMIPS (lpj=2794748) Sep 12 05:53:17.830788 kernel: x86/cpu: User Mode Instruction Prevention (UMIP) activated Sep 12 05:53:17.830798 kernel: Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 Sep 12 05:53:17.830809 kernel: Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 Sep 12 05:53:17.830819 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Sep 12 05:53:17.830830 kernel: Spectre V2 : Mitigation: Retpolines Sep 12 05:53:17.830842 kernel: Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT Sep 12 05:53:17.830853 kernel: Spectre V2 : Enabling Speculation Barrier for firmware calls Sep 12 05:53:17.830863 kernel: active return thunk: retbleed_return_thunk Sep 12 05:53:17.830873 kernel: RETBleed: Mitigation: untrained return thunk Sep 12 05:53:17.830884 kernel: Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier Sep 12 05:53:17.830894 kernel: Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl Sep 12 05:53:17.830905 kernel: Speculative Return Stack Overflow: IBPB-extending microcode not applied! Sep 12 05:53:17.830916 kernel: Speculative Return Stack Overflow: WARNING: See https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for mitigation options. Sep 12 05:53:17.830929 kernel: active return thunk: srso_return_thunk Sep 12 05:53:17.830939 kernel: Speculative Return Stack Overflow: Vulnerable: Safe RET, no microcode Sep 12 05:53:17.830950 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Sep 12 05:53:17.830960 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Sep 12 05:53:17.830970 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Sep 12 05:53:17.830981 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Sep 12 05:53:17.830991 kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. Sep 12 05:53:17.831002 kernel: Freeing SMP alternatives memory: 32K Sep 12 05:53:17.831012 kernel: pid_max: default: 32768 minimum: 301 Sep 12 05:53:17.831025 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,ima Sep 12 05:53:17.831035 kernel: landlock: Up and running. Sep 12 05:53:17.831045 kernel: SELinux: Initializing. Sep 12 05:53:17.831058 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Sep 12 05:53:17.831069 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Sep 12 05:53:17.831079 kernel: smpboot: CPU0: AMD EPYC 7402P 24-Core Processor (family: 0x17, model: 0x31, stepping: 0x0) Sep 12 05:53:17.831090 kernel: Performance Events: Fam17h+ core perfctr, AMD PMU driver. Sep 12 05:53:17.831100 kernel: ... version: 0 Sep 12 05:53:17.831127 kernel: ... bit width: 48 Sep 12 05:53:17.831141 kernel: ... generic registers: 6 Sep 12 05:53:17.831160 kernel: ... value mask: 0000ffffffffffff Sep 12 05:53:17.831171 kernel: ... max period: 00007fffffffffff Sep 12 05:53:17.831181 kernel: ... fixed-purpose events: 0 Sep 12 05:53:17.831191 kernel: ... event mask: 000000000000003f Sep 12 05:53:17.831201 kernel: signal: max sigframe size: 1776 Sep 12 05:53:17.831212 kernel: rcu: Hierarchical SRCU implementation. Sep 12 05:53:17.831222 kernel: rcu: Max phase no-delay instances is 400. Sep 12 05:53:17.831233 kernel: Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level Sep 12 05:53:17.831247 kernel: smp: Bringing up secondary CPUs ... Sep 12 05:53:17.831257 kernel: smpboot: x86: Booting SMP configuration: Sep 12 05:53:17.831267 kernel: .... node #0, CPUs: #1 #2 #3 Sep 12 05:53:17.831278 kernel: smp: Brought up 1 node, 4 CPUs Sep 12 05:53:17.831288 kernel: smpboot: Total of 4 processors activated (22357.98 BogoMIPS) Sep 12 05:53:17.831299 kernel: Memory: 2428920K/2571752K available (14336K kernel code, 2432K rwdata, 9988K rodata, 54092K init, 2872K bss, 136904K reserved, 0K cma-reserved) Sep 12 05:53:17.831309 kernel: devtmpfs: initialized Sep 12 05:53:17.831320 kernel: x86/mm: Memory block size: 128MB Sep 12 05:53:17.831330 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Sep 12 05:53:17.831343 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Sep 12 05:53:17.831353 kernel: pinctrl core: initialized pinctrl subsystem Sep 12 05:53:17.831375 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Sep 12 05:53:17.831386 kernel: audit: initializing netlink subsys (disabled) Sep 12 05:53:17.831396 kernel: audit: type=2000 audit(1757656394.780:1): state=initialized audit_enabled=0 res=1 Sep 12 05:53:17.831406 kernel: thermal_sys: Registered thermal governor 'step_wise' Sep 12 05:53:17.831427 kernel: thermal_sys: Registered thermal governor 'user_space' Sep 12 05:53:17.831447 kernel: cpuidle: using governor menu Sep 12 05:53:17.831458 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Sep 12 05:53:17.831472 kernel: dca service started, version 1.12.1 Sep 12 05:53:17.831483 kernel: PCI: ECAM [mem 0xb0000000-0xbfffffff] (base 0xb0000000) for domain 0000 [bus 00-ff] Sep 12 05:53:17.831494 kernel: PCI: ECAM [mem 0xb0000000-0xbfffffff] reserved as E820 entry Sep 12 05:53:17.831514 kernel: PCI: Using configuration type 1 for base access Sep 12 05:53:17.831534 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Sep 12 05:53:17.831546 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Sep 12 05:53:17.831557 kernel: HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page Sep 12 05:53:17.831568 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Sep 12 05:53:17.831579 kernel: HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page Sep 12 05:53:17.831594 kernel: ACPI: Added _OSI(Module Device) Sep 12 05:53:17.831605 kernel: ACPI: Added _OSI(Processor Device) Sep 12 05:53:17.831617 kernel: ACPI: Added _OSI(Processor Aggregator Device) Sep 12 05:53:17.831628 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Sep 12 05:53:17.831639 kernel: ACPI: Interpreter enabled Sep 12 05:53:17.831650 kernel: ACPI: PM: (supports S0 S3 S5) Sep 12 05:53:17.831661 kernel: ACPI: Using IOAPIC for interrupt routing Sep 12 05:53:17.831672 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Sep 12 05:53:17.831683 kernel: PCI: Using E820 reservations for host bridge windows Sep 12 05:53:17.831697 kernel: ACPI: Enabled 2 GPEs in block 00 to 3F Sep 12 05:53:17.831708 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Sep 12 05:53:17.831956 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Sep 12 05:53:17.832128 kernel: acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR] Sep 12 05:53:17.832294 kernel: acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability] Sep 12 05:53:17.832309 kernel: PCI host bridge to bus 0000:00 Sep 12 05:53:17.832466 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Sep 12 05:53:17.832608 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Sep 12 05:53:17.832744 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Sep 12 05:53:17.832893 kernel: pci_bus 0000:00: root bus resource [mem 0x9d000000-0xafffffff window] Sep 12 05:53:17.833040 kernel: pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] Sep 12 05:53:17.833233 kernel: pci_bus 0000:00: root bus resource [mem 0x100000000-0x8ffffffff window] Sep 12 05:53:17.833420 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Sep 12 05:53:17.833619 kernel: pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 conventional PCI endpoint Sep 12 05:53:17.833798 kernel: pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint Sep 12 05:53:17.833952 kernel: pci 0000:00:01.0: BAR 0 [mem 0xfd000000-0xfdffffff pref] Sep 12 05:53:17.834122 kernel: pci 0000:00:01.0: BAR 2 [mem 0xfebd0000-0xfebd0fff] Sep 12 05:53:17.834296 kernel: pci 0000:00:01.0: ROM [mem 0xfebc0000-0xfebcffff pref] Sep 12 05:53:17.834449 kernel: pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Sep 12 05:53:17.834619 kernel: pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint Sep 12 05:53:17.834777 kernel: pci 0000:00:02.0: BAR 0 [io 0xc0c0-0xc0df] Sep 12 05:53:17.834961 kernel: pci 0000:00:02.0: BAR 1 [mem 0xfebd1000-0xfebd1fff] Sep 12 05:53:17.835211 kernel: pci 0000:00:02.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref] Sep 12 05:53:17.835387 kernel: pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint Sep 12 05:53:17.835551 kernel: pci 0000:00:03.0: BAR 0 [io 0xc000-0xc07f] Sep 12 05:53:17.835719 kernel: pci 0000:00:03.0: BAR 1 [mem 0xfebd2000-0xfebd2fff] Sep 12 05:53:17.835871 kernel: pci 0000:00:03.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref] Sep 12 05:53:17.836040 kernel: pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint Sep 12 05:53:17.836278 kernel: pci 0000:00:04.0: BAR 0 [io 0xc0e0-0xc0ff] Sep 12 05:53:17.836453 kernel: pci 0000:00:04.0: BAR 1 [mem 0xfebd3000-0xfebd3fff] Sep 12 05:53:17.836605 kernel: pci 0000:00:04.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref] Sep 12 05:53:17.836767 kernel: pci 0000:00:04.0: ROM [mem 0xfeb80000-0xfebbffff pref] Sep 12 05:53:17.836951 kernel: pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 conventional PCI endpoint Sep 12 05:53:17.837124 kernel: pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO Sep 12 05:53:17.837312 kernel: pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 conventional PCI endpoint Sep 12 05:53:17.837465 kernel: pci 0000:00:1f.2: BAR 4 [io 0xc100-0xc11f] Sep 12 05:53:17.837614 kernel: pci 0000:00:1f.2: BAR 5 [mem 0xfebd4000-0xfebd4fff] Sep 12 05:53:17.837778 kernel: pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 conventional PCI endpoint Sep 12 05:53:17.837931 kernel: pci 0000:00:1f.3: BAR 4 [io 0x0700-0x073f] Sep 12 05:53:17.837947 kernel: ACPI: PCI: Interrupt link LNKA configured for IRQ 10 Sep 12 05:53:17.837959 kernel: ACPI: PCI: Interrupt link LNKB configured for IRQ 10 Sep 12 05:53:17.837974 kernel: ACPI: PCI: Interrupt link LNKC configured for IRQ 11 Sep 12 05:53:17.837986 kernel: ACPI: PCI: Interrupt link LNKD configured for IRQ 11 Sep 12 05:53:17.837997 kernel: ACPI: PCI: Interrupt link LNKE configured for IRQ 10 Sep 12 05:53:17.838008 kernel: ACPI: PCI: Interrupt link LNKF configured for IRQ 10 Sep 12 05:53:17.838019 kernel: ACPI: PCI: Interrupt link LNKG configured for IRQ 11 Sep 12 05:53:17.838030 kernel: ACPI: PCI: Interrupt link LNKH configured for IRQ 11 Sep 12 05:53:17.838041 kernel: ACPI: PCI: Interrupt link GSIA configured for IRQ 16 Sep 12 05:53:17.838052 kernel: ACPI: PCI: Interrupt link GSIB configured for IRQ 17 Sep 12 05:53:17.838063 kernel: ACPI: PCI: Interrupt link GSIC configured for IRQ 18 Sep 12 05:53:17.838077 kernel: ACPI: PCI: Interrupt link GSID configured for IRQ 19 Sep 12 05:53:17.838088 kernel: ACPI: PCI: Interrupt link GSIE configured for IRQ 20 Sep 12 05:53:17.838099 kernel: ACPI: PCI: Interrupt link GSIF configured for IRQ 21 Sep 12 05:53:17.838126 kernel: ACPI: PCI: Interrupt link GSIG configured for IRQ 22 Sep 12 05:53:17.838138 kernel: ACPI: PCI: Interrupt link GSIH configured for IRQ 23 Sep 12 05:53:17.838159 kernel: iommu: Default domain type: Translated Sep 12 05:53:17.838170 kernel: iommu: DMA domain TLB invalidation policy: lazy mode Sep 12 05:53:17.838181 kernel: PCI: Using ACPI for IRQ routing Sep 12 05:53:17.838192 kernel: PCI: pci_cache_line_size set to 64 bytes Sep 12 05:53:17.838207 kernel: e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] Sep 12 05:53:17.838218 kernel: e820: reserve RAM buffer [mem 0x9cfdc000-0x9fffffff] Sep 12 05:53:17.838375 kernel: pci 0000:00:01.0: vgaarb: setting as boot VGA device Sep 12 05:53:17.838528 kernel: pci 0000:00:01.0: vgaarb: bridge control possible Sep 12 05:53:17.838681 kernel: pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Sep 12 05:53:17.838696 kernel: vgaarb: loaded Sep 12 05:53:17.838707 kernel: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Sep 12 05:53:17.838719 kernel: hpet0: 3 comparators, 64-bit 100.000000 MHz counter Sep 12 05:53:17.838734 kernel: clocksource: Switched to clocksource kvm-clock Sep 12 05:53:17.838746 kernel: VFS: Disk quotas dquot_6.6.0 Sep 12 05:53:17.838757 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Sep 12 05:53:17.838768 kernel: pnp: PnP ACPI init Sep 12 05:53:17.838938 kernel: system 00:05: [mem 0xb0000000-0xbfffffff window] has been reserved Sep 12 05:53:17.838955 kernel: pnp: PnP ACPI: found 6 devices Sep 12 05:53:17.838966 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Sep 12 05:53:17.838977 kernel: NET: Registered PF_INET protocol family Sep 12 05:53:17.838993 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Sep 12 05:53:17.839004 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Sep 12 05:53:17.839015 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Sep 12 05:53:17.839026 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Sep 12 05:53:17.839037 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Sep 12 05:53:17.839049 kernel: TCP: Hash tables configured (established 32768 bind 32768) Sep 12 05:53:17.839060 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Sep 12 05:53:17.839070 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Sep 12 05:53:17.839082 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Sep 12 05:53:17.839096 kernel: NET: Registered PF_XDP protocol family Sep 12 05:53:17.839269 kernel: pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] Sep 12 05:53:17.839411 kernel: pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] Sep 12 05:53:17.839567 kernel: pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] Sep 12 05:53:17.839715 kernel: pci_bus 0000:00: resource 7 [mem 0x9d000000-0xafffffff window] Sep 12 05:53:17.839858 kernel: pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window] Sep 12 05:53:17.839998 kernel: pci_bus 0000:00: resource 9 [mem 0x100000000-0x8ffffffff window] Sep 12 05:53:17.840013 kernel: PCI: CLS 0 bytes, default 64 Sep 12 05:53:17.840029 kernel: clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2848df6a9de, max_idle_ns: 440795280912 ns Sep 12 05:53:17.840041 kernel: Initialise system trusted keyrings Sep 12 05:53:17.840052 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Sep 12 05:53:17.840063 kernel: Key type asymmetric registered Sep 12 05:53:17.840074 kernel: Asymmetric key parser 'x509' registered Sep 12 05:53:17.840086 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) Sep 12 05:53:17.840097 kernel: io scheduler mq-deadline registered Sep 12 05:53:17.840126 kernel: io scheduler kyber registered Sep 12 05:53:17.840138 kernel: io scheduler bfq registered Sep 12 05:53:17.840161 kernel: ioatdma: Intel(R) QuickData Technology Driver 5.00 Sep 12 05:53:17.840172 kernel: ACPI: \_SB_.GSIG: Enabled at IRQ 22 Sep 12 05:53:17.840183 kernel: ACPI: \_SB_.GSIH: Enabled at IRQ 23 Sep 12 05:53:17.840194 kernel: ACPI: \_SB_.GSIE: Enabled at IRQ 20 Sep 12 05:53:17.840205 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Sep 12 05:53:17.840217 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Sep 12 05:53:17.840228 kernel: i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Sep 12 05:53:17.840239 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Sep 12 05:53:17.840251 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Sep 12 05:53:17.840417 kernel: rtc_cmos 00:04: RTC can wake from S4 Sep 12 05:53:17.840434 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 Sep 12 05:53:17.840577 kernel: rtc_cmos 00:04: registered as rtc0 Sep 12 05:53:17.840725 kernel: rtc_cmos 00:04: setting system clock to 2025-09-12T05:53:17 UTC (1757656397) Sep 12 05:53:17.840872 kernel: rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram, hpet irqs Sep 12 05:53:17.840887 kernel: amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled Sep 12 05:53:17.840898 kernel: NET: Registered PF_INET6 protocol family Sep 12 05:53:17.840909 kernel: Segment Routing with IPv6 Sep 12 05:53:17.840925 kernel: In-situ OAM (IOAM) with IPv6 Sep 12 05:53:17.840936 kernel: NET: Registered PF_PACKET protocol family Sep 12 05:53:17.840947 kernel: Key type dns_resolver registered Sep 12 05:53:17.840958 kernel: IPI shorthand broadcast: enabled Sep 12 05:53:17.840969 kernel: sched_clock: Marking stable (3235002717, 217680721)->(3526916056, -74232618) Sep 12 05:53:17.840980 kernel: registered taskstats version 1 Sep 12 05:53:17.840992 kernel: Loading compiled-in X.509 certificates Sep 12 05:53:17.841003 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.12.46-flatcar: c974434132f0296e0aaf9b1358c8dc50eba5c8b9' Sep 12 05:53:17.841014 kernel: Demotion targets for Node 0: null Sep 12 05:53:17.841029 kernel: Key type .fscrypt registered Sep 12 05:53:17.841040 kernel: Key type fscrypt-provisioning registered Sep 12 05:53:17.841051 kernel: ima: No TPM chip found, activating TPM-bypass! Sep 12 05:53:17.841062 kernel: ima: Allocated hash algorithm: sha1 Sep 12 05:53:17.841073 kernel: ima: No architecture policies found Sep 12 05:53:17.841084 kernel: clk: Disabling unused clocks Sep 12 05:53:17.841095 kernel: Warning: unable to open an initial console. Sep 12 05:53:17.841128 kernel: Freeing unused kernel image (initmem) memory: 54092K Sep 12 05:53:17.841140 kernel: Write protecting the kernel read-only data: 24576k Sep 12 05:53:17.841182 kernel: Freeing unused kernel image (rodata/data gap) memory: 252K Sep 12 05:53:17.841194 kernel: Run /init as init process Sep 12 05:53:17.841205 kernel: with arguments: Sep 12 05:53:17.841216 kernel: /init Sep 12 05:53:17.841227 kernel: with environment: Sep 12 05:53:17.841237 kernel: HOME=/ Sep 12 05:53:17.841247 kernel: TERM=linux Sep 12 05:53:17.841258 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a Sep 12 05:53:17.841271 systemd[1]: Successfully made /usr/ read-only. Sep 12 05:53:17.841300 systemd[1]: systemd 256.8 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP -GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) Sep 12 05:53:17.841316 systemd[1]: Detected virtualization kvm. Sep 12 05:53:17.841328 systemd[1]: Detected architecture x86-64. Sep 12 05:53:17.841340 systemd[1]: Running in initrd. Sep 12 05:53:17.841352 systemd[1]: No hostname configured, using default hostname. Sep 12 05:53:17.841367 systemd[1]: Hostname set to . Sep 12 05:53:17.841379 systemd[1]: Initializing machine ID from VM UUID. Sep 12 05:53:17.841391 systemd[1]: Queued start job for default target initrd.target. Sep 12 05:53:17.841404 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Sep 12 05:53:17.841416 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Sep 12 05:53:17.841432 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Sep 12 05:53:17.841445 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Sep 12 05:53:17.841457 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Sep 12 05:53:17.841474 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Sep 12 05:53:17.841487 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... Sep 12 05:53:17.841500 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... Sep 12 05:53:17.841512 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Sep 12 05:53:17.841527 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Sep 12 05:53:17.841540 systemd[1]: Reached target paths.target - Path Units. Sep 12 05:53:17.841552 systemd[1]: Reached target slices.target - Slice Units. Sep 12 05:53:17.841567 systemd[1]: Reached target swap.target - Swaps. Sep 12 05:53:17.841579 systemd[1]: Reached target timers.target - Timer Units. Sep 12 05:53:17.841591 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Sep 12 05:53:17.841604 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Sep 12 05:53:17.841616 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Sep 12 05:53:17.841628 systemd[1]: Listening on systemd-journald.socket - Journal Sockets. Sep 12 05:53:17.841640 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Sep 12 05:53:17.841652 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Sep 12 05:53:17.841667 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Sep 12 05:53:17.841679 systemd[1]: Reached target sockets.target - Socket Units. Sep 12 05:53:17.841691 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Sep 12 05:53:17.841703 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Sep 12 05:53:17.841718 systemd[1]: Finished network-cleanup.service - Network Cleanup. Sep 12 05:53:17.841731 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). Sep 12 05:53:17.841748 systemd[1]: Starting systemd-fsck-usr.service... Sep 12 05:53:17.841760 systemd[1]: Starting systemd-journald.service - Journal Service... Sep 12 05:53:17.841773 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Sep 12 05:53:17.841785 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Sep 12 05:53:17.841797 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Sep 12 05:53:17.841812 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Sep 12 05:53:17.841825 systemd[1]: Finished systemd-fsck-usr.service. Sep 12 05:53:17.841837 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Sep 12 05:53:17.841890 systemd-journald[220]: Collecting audit messages is disabled. Sep 12 05:53:17.841957 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Sep 12 05:53:17.841970 systemd-journald[220]: Journal started Sep 12 05:53:17.841997 systemd-journald[220]: Runtime Journal (/run/log/journal/14c0f2d84eb447c59efe498951c6fef9) is 6M, max 48.6M, 42.5M free. Sep 12 05:53:17.833480 systemd-modules-load[222]: Inserted module 'overlay' Sep 12 05:53:17.865763 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Sep 12 05:53:17.865805 kernel: Bridge firewalling registered Sep 12 05:53:17.867187 systemd-modules-load[222]: Inserted module 'br_netfilter' Sep 12 05:53:17.871529 systemd[1]: Started systemd-journald.service - Journal Service. Sep 12 05:53:17.872872 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Sep 12 05:53:17.875314 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Sep 12 05:53:17.882859 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Sep 12 05:53:17.886360 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Sep 12 05:53:17.893931 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Sep 12 05:53:17.897733 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Sep 12 05:53:17.905304 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Sep 12 05:53:17.910300 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Sep 12 05:53:17.912410 systemd-tmpfiles[246]: /usr/lib/tmpfiles.d/var.conf:14: Duplicate line for path "/var/log", ignoring. Sep 12 05:53:17.918269 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Sep 12 05:53:17.921070 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Sep 12 05:53:17.925917 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Sep 12 05:53:17.930790 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Sep 12 05:53:17.957206 dracut-cmdline[264]: 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=d36684c42387dba16669740eb40ca6a094be0dfb03f64a303630b6ac6cfe48d3 Sep 12 05:53:17.966611 systemd-resolved[260]: Positive Trust Anchors: Sep 12 05:53:17.966635 systemd-resolved[260]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Sep 12 05:53:17.966664 systemd-resolved[260]: 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 Sep 12 05:53:17.969519 systemd-resolved[260]: Defaulting to hostname 'linux'. Sep 12 05:53:17.970886 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Sep 12 05:53:17.976679 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Sep 12 05:53:18.059146 kernel: SCSI subsystem initialized Sep 12 05:53:18.069131 kernel: Loading iSCSI transport class v2.0-870. Sep 12 05:53:18.079134 kernel: iscsi: registered transport (tcp) Sep 12 05:53:18.105169 kernel: iscsi: registered transport (qla4xxx) Sep 12 05:53:18.105255 kernel: QLogic iSCSI HBA Driver Sep 12 05:53:18.128068 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Sep 12 05:53:18.157728 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Sep 12 05:53:18.160184 systemd[1]: Reached target network-pre.target - Preparation for Network. Sep 12 05:53:18.221429 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Sep 12 05:53:18.224293 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Sep 12 05:53:18.288167 kernel: raid6: avx2x4 gen() 30224 MB/s Sep 12 05:53:18.305154 kernel: raid6: avx2x2 gen() 30669 MB/s Sep 12 05:53:18.322241 kernel: raid6: avx2x1 gen() 25517 MB/s Sep 12 05:53:18.322271 kernel: raid6: using algorithm avx2x2 gen() 30669 MB/s Sep 12 05:53:18.340195 kernel: raid6: .... xor() 19687 MB/s, rmw enabled Sep 12 05:53:18.340252 kernel: raid6: using avx2x2 recovery algorithm Sep 12 05:53:18.360144 kernel: xor: automatically using best checksumming function avx Sep 12 05:53:18.525165 kernel: Btrfs loaded, zoned=no, fsverity=no Sep 12 05:53:18.534513 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Sep 12 05:53:18.536346 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Sep 12 05:53:18.564298 systemd-udevd[474]: Using default interface naming scheme 'v255'. Sep 12 05:53:18.570084 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Sep 12 05:53:18.571022 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Sep 12 05:53:18.609808 dracut-pre-trigger[478]: rd.md=0: removing MD RAID activation Sep 12 05:53:18.638916 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Sep 12 05:53:18.642527 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Sep 12 05:53:18.726466 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Sep 12 05:53:18.730336 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Sep 12 05:53:18.768142 kernel: virtio_blk virtio1: 4/0/0 default/read/poll queues Sep 12 05:53:18.771130 kernel: virtio_blk virtio1: [vda] 9289728 512-byte logical blocks (4.76 GB/4.43 GiB) Sep 12 05:53:18.776148 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Sep 12 05:53:18.787142 kernel: cryptd: max_cpu_qlen set to 1000 Sep 12 05:53:18.800148 kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input2 Sep 12 05:53:18.803408 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Sep 12 05:53:18.803686 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Sep 12 05:53:18.805972 kernel: libata version 3.00 loaded. Sep 12 05:53:18.807663 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Sep 12 05:53:18.812295 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Sep 12 05:53:18.817137 kernel: AES CTR mode by8 optimization enabled Sep 12 05:53:18.817175 kernel: ahci 0000:00:1f.2: version 3.0 Sep 12 05:53:18.817361 kernel: ACPI: \_SB_.GSIA: Enabled at IRQ 16 Sep 12 05:53:18.817562 systemd[1]: run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Deactivated successfully. Sep 12 05:53:18.830280 kernel: ahci 0000:00:1f.2: AHCI vers 0001.0000, 32 command slots, 1.5 Gbps, SATA mode Sep 12 05:53:18.830634 kernel: ahci 0000:00:1f.2: 6/6 ports implemented (port mask 0x3f) Sep 12 05:53:18.830801 kernel: ahci 0000:00:1f.2: flags: 64bit ncq only Sep 12 05:53:18.849249 kernel: scsi host0: ahci Sep 12 05:53:18.849555 kernel: scsi host1: ahci Sep 12 05:53:18.852190 kernel: scsi host2: ahci Sep 12 05:53:18.852372 kernel: scsi host3: ahci Sep 12 05:53:18.853259 kernel: scsi host4: ahci Sep 12 05:53:18.854194 kernel: scsi host5: ahci Sep 12 05:53:18.854489 kernel: ata1: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4100 irq 34 lpm-pol 1 Sep 12 05:53:18.855947 kernel: ata2: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4180 irq 34 lpm-pol 1 Sep 12 05:53:18.855974 kernel: ata3: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4200 irq 34 lpm-pol 1 Sep 12 05:53:18.857357 kernel: ata4: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4280 irq 34 lpm-pol 1 Sep 12 05:53:18.857644 kernel: ata5: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4300 irq 34 lpm-pol 1 Sep 12 05:53:18.859137 kernel: ata6: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4380 irq 34 lpm-pol 1 Sep 12 05:53:18.860714 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Sep 12 05:53:18.877613 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Sep 12 05:53:18.902681 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132. Sep 12 05:53:18.905751 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Sep 12 05:53:18.906041 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Sep 12 05:53:18.919690 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Sep 12 05:53:18.922213 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Sep 12 05:53:19.084151 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Sep 12 05:53:19.163134 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Sep 12 05:53:19.166155 kernel: ata1: SATA link down (SStatus 0 SControl 300) Sep 12 05:53:19.174174 kernel: ata4: SATA link down (SStatus 0 SControl 300) Sep 12 05:53:19.174240 kernel: ata5: SATA link down (SStatus 0 SControl 300) Sep 12 05:53:19.176153 kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Sep 12 05:53:19.176182 kernel: ata2: SATA link down (SStatus 0 SControl 300) Sep 12 05:53:19.176194 kernel: ata3.00: LPM support broken, forcing max_power Sep 12 05:53:19.177229 kernel: ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 Sep 12 05:53:19.177243 kernel: ata3.00: applying bridge limits Sep 12 05:53:19.178142 kernel: ata6: SATA link down (SStatus 0 SControl 300) Sep 12 05:53:19.179160 kernel: ata3.00: LPM support broken, forcing max_power Sep 12 05:53:19.180146 kernel: ata3.00: configured for UDMA/100 Sep 12 05:53:19.180216 kernel: scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 Sep 12 05:53:19.247603 kernel: sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Sep 12 05:53:19.247855 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Sep 12 05:53:19.259192 kernel: sr 2:0:0:0: Attached scsi CD-ROM sr0 Sep 12 05:53:19.743673 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Sep 12 05:53:19.746475 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Sep 12 05:53:19.748984 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Sep 12 05:53:19.751231 systemd[1]: Reached target remote-fs.target - Remote File Systems. Sep 12 05:53:19.754146 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Sep 12 05:53:19.789141 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Sep 12 05:53:20.169131 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Sep 12 05:53:20.169512 disk-uuid[637]: The operation has completed successfully. Sep 12 05:53:20.198443 systemd[1]: disk-uuid.service: Deactivated successfully. Sep 12 05:53:20.198601 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Sep 12 05:53:20.237747 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... Sep 12 05:53:20.267921 sh[665]: Success Sep 12 05:53:20.286140 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Sep 12 05:53:20.286204 kernel: device-mapper: uevent: version 1.0.3 Sep 12 05:53:20.288150 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev Sep 12 05:53:20.395145 kernel: device-mapper: verity: sha256 using shash "sha256-ni" Sep 12 05:53:20.425414 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. Sep 12 05:53:20.427659 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... Sep 12 05:53:20.442474 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. Sep 12 05:53:20.449147 kernel: BTRFS: device fsid 29ae74b1-0ab1-4a84-96e7-98d98e1ec77f devid 1 transid 35 /dev/mapper/usr (253:0) scanned by mount (677) Sep 12 05:53:20.449222 kernel: BTRFS info (device dm-0): first mount of filesystem 29ae74b1-0ab1-4a84-96e7-98d98e1ec77f Sep 12 05:53:20.451127 kernel: BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm Sep 12 05:53:20.456165 kernel: BTRFS info (device dm-0): disabling log replay at mount time Sep 12 05:53:20.456190 kernel: BTRFS info (device dm-0): enabling free space tree Sep 12 05:53:20.457510 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. Sep 12 05:53:20.458882 systemd[1]: Reached target initrd-usr-fs.target - Initrd /usr File System. Sep 12 05:53:20.460314 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Sep 12 05:53:20.461164 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Sep 12 05:53:20.462828 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Sep 12 05:53:20.487029 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (710) Sep 12 05:53:20.487132 kernel: BTRFS info (device vda6): first mount of filesystem 88e8cff7-d302-45f0-bf99-3731957f99ae Sep 12 05:53:20.487184 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Sep 12 05:53:20.491147 kernel: BTRFS info (device vda6): turning on async discard Sep 12 05:53:20.491176 kernel: BTRFS info (device vda6): enabling free space tree Sep 12 05:53:20.496177 kernel: BTRFS info (device vda6): last unmount of filesystem 88e8cff7-d302-45f0-bf99-3731957f99ae Sep 12 05:53:20.497433 systemd[1]: Finished ignition-setup.service - Ignition (setup). Sep 12 05:53:20.499059 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Sep 12 05:53:20.618694 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Sep 12 05:53:20.623703 systemd[1]: Starting systemd-networkd.service - Network Configuration... Sep 12 05:53:20.698603 systemd-networkd[846]: lo: Link UP Sep 12 05:53:20.698615 systemd-networkd[846]: lo: Gained carrier Sep 12 05:53:20.701430 systemd-networkd[846]: Enumeration completed Sep 12 05:53:20.701557 systemd[1]: Started systemd-networkd.service - Network Configuration. Sep 12 05:53:20.701831 systemd-networkd[846]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Sep 12 05:53:20.701835 systemd-networkd[846]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Sep 12 05:53:20.703365 systemd-networkd[846]: eth0: Link UP Sep 12 05:53:20.703549 systemd-networkd[846]: eth0: Gained carrier Sep 12 05:53:20.703559 systemd-networkd[846]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Sep 12 05:53:20.705405 systemd[1]: Reached target network.target - Network. Sep 12 05:53:20.727052 ignition[752]: Ignition 2.22.0 Sep 12 05:53:20.727073 ignition[752]: Stage: fetch-offline Sep 12 05:53:20.727134 ignition[752]: no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:20.727145 ignition[752]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:20.727240 ignition[752]: parsed url from cmdline: "" Sep 12 05:53:20.727244 ignition[752]: no config URL provided Sep 12 05:53:20.727253 ignition[752]: reading system config file "/usr/lib/ignition/user.ign" Sep 12 05:53:20.731173 systemd-networkd[846]: eth0: DHCPv4 address 10.0.0.69/16, gateway 10.0.0.1 acquired from 10.0.0.1 Sep 12 05:53:20.727262 ignition[752]: no config at "/usr/lib/ignition/user.ign" Sep 12 05:53:20.727284 ignition[752]: op(1): [started] loading QEMU firmware config module Sep 12 05:53:20.727289 ignition[752]: op(1): executing: "modprobe" "qemu_fw_cfg" Sep 12 05:53:20.738791 ignition[752]: op(1): [finished] loading QEMU firmware config module Sep 12 05:53:20.740236 ignition[752]: parsing config with SHA512: d046f42b38c0542db8c15e67b98abc23d582e5a7e2343182e67adfbd7e3633b8cc213c801b9d882e268db4972eb7ad0d948af20e25178224a2379af6ef1fece1 Sep 12 05:53:20.747204 unknown[752]: fetched base config from "system" Sep 12 05:53:20.747218 unknown[752]: fetched user config from "qemu" Sep 12 05:53:20.747364 ignition[752]: fetch-offline: fetch-offline passed Sep 12 05:53:20.747451 ignition[752]: Ignition finished successfully Sep 12 05:53:20.753458 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Sep 12 05:53:20.753751 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Sep 12 05:53:20.754634 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Sep 12 05:53:20.822689 ignition[859]: Ignition 2.22.0 Sep 12 05:53:20.822704 ignition[859]: Stage: kargs Sep 12 05:53:20.822854 ignition[859]: no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:20.822866 ignition[859]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:20.825947 ignition[859]: kargs: kargs passed Sep 12 05:53:20.825995 ignition[859]: Ignition finished successfully Sep 12 05:53:20.831798 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Sep 12 05:53:20.834866 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Sep 12 05:53:20.896133 ignition[866]: Ignition 2.22.0 Sep 12 05:53:20.896146 ignition[866]: Stage: disks Sep 12 05:53:20.896340 ignition[866]: no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:20.896352 ignition[866]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:20.897124 ignition[866]: disks: disks passed Sep 12 05:53:20.897174 ignition[866]: Ignition finished successfully Sep 12 05:53:20.903671 systemd[1]: Finished ignition-disks.service - Ignition (disks). Sep 12 05:53:20.905792 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Sep 12 05:53:20.905882 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Sep 12 05:53:20.907880 systemd[1]: Reached target local-fs.target - Local File Systems. Sep 12 05:53:20.910078 systemd[1]: Reached target sysinit.target - System Initialization. Sep 12 05:53:20.912809 systemd[1]: Reached target basic.target - Basic System. Sep 12 05:53:20.915634 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Sep 12 05:53:20.953874 systemd-fsck[876]: ROOT: clean, 15/553520 files, 52789/553472 blocks Sep 12 05:53:21.041778 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Sep 12 05:53:21.043007 systemd[1]: Mounting sysroot.mount - /sysroot... Sep 12 05:53:21.156167 kernel: EXT4-fs (vda9): mounted filesystem 2b8062f9-897a-46cb-bde4-2b62ba4cc712 r/w with ordered data mode. Quota mode: none. Sep 12 05:53:21.156729 systemd[1]: Mounted sysroot.mount - /sysroot. Sep 12 05:53:21.158838 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Sep 12 05:53:21.162170 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Sep 12 05:53:21.164568 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Sep 12 05:53:21.166478 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Sep 12 05:53:21.166525 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Sep 12 05:53:21.166547 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Sep 12 05:53:21.192928 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Sep 12 05:53:21.194516 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Sep 12 05:53:21.200141 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (884) Sep 12 05:53:21.202125 kernel: BTRFS info (device vda6): first mount of filesystem 88e8cff7-d302-45f0-bf99-3731957f99ae Sep 12 05:53:21.202144 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Sep 12 05:53:21.205138 kernel: BTRFS info (device vda6): turning on async discard Sep 12 05:53:21.205170 kernel: BTRFS info (device vda6): enabling free space tree Sep 12 05:53:21.344882 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Sep 12 05:53:21.402623 initrd-setup-root[908]: cut: /sysroot/etc/passwd: No such file or directory Sep 12 05:53:21.408827 initrd-setup-root[915]: cut: /sysroot/etc/group: No such file or directory Sep 12 05:53:21.413747 initrd-setup-root[922]: cut: /sysroot/etc/shadow: No such file or directory Sep 12 05:53:21.419516 initrd-setup-root[929]: cut: /sysroot/etc/gshadow: No such file or directory Sep 12 05:53:21.523513 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Sep 12 05:53:21.525796 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Sep 12 05:53:21.527792 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Sep 12 05:53:21.546430 systemd[1]: sysroot-oem.mount: Deactivated successfully. Sep 12 05:53:21.547646 kernel: BTRFS info (device vda6): last unmount of filesystem 88e8cff7-d302-45f0-bf99-3731957f99ae Sep 12 05:53:21.564492 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Sep 12 05:53:21.595531 ignition[998]: INFO : Ignition 2.22.0 Sep 12 05:53:21.595531 ignition[998]: INFO : Stage: mount Sep 12 05:53:21.597197 ignition[998]: INFO : no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:21.597197 ignition[998]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:21.597197 ignition[998]: INFO : mount: mount passed Sep 12 05:53:21.597197 ignition[998]: INFO : Ignition finished successfully Sep 12 05:53:21.603692 systemd[1]: Finished ignition-mount.service - Ignition (mount). Sep 12 05:53:21.607028 systemd[1]: Starting ignition-files.service - Ignition (files)... Sep 12 05:53:21.640726 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Sep 12 05:53:21.653136 kernel: BTRFS: device label OEM devid 1 transid 11 /dev/vda6 (254:6) scanned by mount (1010) Sep 12 05:53:21.655370 kernel: BTRFS info (device vda6): first mount of filesystem 88e8cff7-d302-45f0-bf99-3731957f99ae Sep 12 05:53:21.655391 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Sep 12 05:53:21.658251 kernel: BTRFS info (device vda6): turning on async discard Sep 12 05:53:21.658321 kernel: BTRFS info (device vda6): enabling free space tree Sep 12 05:53:21.659932 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Sep 12 05:53:21.705704 ignition[1027]: INFO : Ignition 2.22.0 Sep 12 05:53:21.705704 ignition[1027]: INFO : Stage: files Sep 12 05:53:21.707443 ignition[1027]: INFO : no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:21.707443 ignition[1027]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:21.710258 ignition[1027]: DEBUG : files: compiled without relabeling support, skipping Sep 12 05:53:21.711598 ignition[1027]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Sep 12 05:53:21.711598 ignition[1027]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Sep 12 05:53:21.716194 ignition[1027]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Sep 12 05:53:21.717797 ignition[1027]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Sep 12 05:53:21.719635 unknown[1027]: wrote ssh authorized keys file for user: core Sep 12 05:53:21.720982 ignition[1027]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Sep 12 05:53:21.726740 ignition[1027]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/etc/flatcar/update.conf" Sep 12 05:53:21.728955 ignition[1027]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/etc/flatcar/update.conf" Sep 12 05:53:21.728955 ignition[1027]: INFO : files: op(4): [started] processing unit "etcd-member.service" Sep 12 05:53:21.728955 ignition[1027]: 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" Sep 12 05:53:21.735254 ignition[1027]: 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" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(4): [finished] processing unit "etcd-member.service" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(6): [started] processing unit "coreos-metadata.service" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(6): op(7): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(6): op(7): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(6): [finished] processing unit "coreos-metadata.service" Sep 12 05:53:21.735254 ignition[1027]: INFO : files: op(8): [started] setting preset to disabled for "coreos-metadata.service" Sep 12 05:53:21.767751 ignition[1027]: INFO : files: op(8): op(9): [started] removing enablement symlink(s) for "coreos-metadata.service" Sep 12 05:53:21.775004 ignition[1027]: INFO : files: op(8): op(9): [finished] removing enablement symlink(s) for "coreos-metadata.service" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: op(8): [finished] setting preset to disabled for "coreos-metadata.service" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: op(a): [started] setting preset to enabled for "etcd-member.service" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: op(a): [finished] setting preset to enabled for "etcd-member.service" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Sep 12 05:53:21.776785 ignition[1027]: INFO : files: files passed Sep 12 05:53:21.776785 ignition[1027]: INFO : Ignition finished successfully Sep 12 05:53:21.783422 systemd[1]: Finished ignition-files.service - Ignition (files). Sep 12 05:53:21.785277 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Sep 12 05:53:21.791523 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Sep 12 05:53:21.803129 systemd[1]: ignition-quench.service: Deactivated successfully. Sep 12 05:53:21.803274 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Sep 12 05:53:21.806487 initrd-setup-root-after-ignition[1055]: grep: /sysroot/oem/oem-release: No such file or directory Sep 12 05:53:21.807908 initrd-setup-root-after-ignition[1058]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Sep 12 05:53:21.807908 initrd-setup-root-after-ignition[1058]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Sep 12 05:53:21.811074 initrd-setup-root-after-ignition[1062]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Sep 12 05:53:21.810629 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Sep 12 05:53:21.812481 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Sep 12 05:53:21.816064 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Sep 12 05:53:21.869765 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Sep 12 05:53:21.869913 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Sep 12 05:53:21.871201 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Sep 12 05:53:21.873338 systemd[1]: Reached target initrd.target - Initrd Default Target. Sep 12 05:53:21.875457 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Sep 12 05:53:21.878801 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Sep 12 05:53:21.904832 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Sep 12 05:53:21.907295 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Sep 12 05:53:21.937794 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Sep 12 05:53:21.937952 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Sep 12 05:53:21.940220 systemd[1]: Stopped target timers.target - Timer Units. Sep 12 05:53:21.942569 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Sep 12 05:53:21.942684 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Sep 12 05:53:21.945659 systemd[1]: Stopped target initrd.target - Initrd Default Target. Sep 12 05:53:21.947807 systemd[1]: Stopped target basic.target - Basic System. Sep 12 05:53:21.949857 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Sep 12 05:53:21.951871 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Sep 12 05:53:21.953867 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Sep 12 05:53:21.955963 systemd[1]: Stopped target initrd-usr-fs.target - Initrd /usr File System. Sep 12 05:53:21.958144 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Sep 12 05:53:21.959215 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Sep 12 05:53:21.960273 systemd[1]: Stopped target sysinit.target - System Initialization. Sep 12 05:53:21.962408 systemd[1]: Stopped target local-fs.target - Local File Systems. Sep 12 05:53:21.964288 systemd[1]: Stopped target swap.target - Swaps. Sep 12 05:53:21.964574 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Sep 12 05:53:21.964686 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Sep 12 05:53:21.968194 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Sep 12 05:53:21.968666 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Sep 12 05:53:21.968949 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Sep 12 05:53:21.973998 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Sep 12 05:53:21.975051 systemd[1]: dracut-initqueue.service: Deactivated successfully. Sep 12 05:53:21.975182 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Sep 12 05:53:21.975837 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Sep 12 05:53:21.975944 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Sep 12 05:53:21.980206 systemd[1]: Stopped target paths.target - Path Units. Sep 12 05:53:21.980579 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Sep 12 05:53:21.987177 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Sep 12 05:53:21.987544 systemd[1]: Stopped target slices.target - Slice Units. Sep 12 05:53:21.987851 systemd[1]: Stopped target sockets.target - Socket Units. Sep 12 05:53:21.988205 systemd[1]: iscsid.socket: Deactivated successfully. Sep 12 05:53:21.988289 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Sep 12 05:53:21.988684 systemd[1]: iscsiuio.socket: Deactivated successfully. Sep 12 05:53:21.988766 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Sep 12 05:53:21.994601 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Sep 12 05:53:21.994711 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Sep 12 05:53:21.996347 systemd[1]: ignition-files.service: Deactivated successfully. Sep 12 05:53:21.996452 systemd[1]: Stopped ignition-files.service - Ignition (files). Sep 12 05:53:22.004316 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Sep 12 05:53:22.006153 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Sep 12 05:53:22.006343 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Sep 12 05:53:22.017870 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Sep 12 05:53:22.018993 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Sep 12 05:53:22.019323 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Sep 12 05:53:22.021198 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Sep 12 05:53:22.021371 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Sep 12 05:53:22.028849 systemd[1]: initrd-cleanup.service: Deactivated successfully. Sep 12 05:53:22.085366 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Sep 12 05:53:22.102906 ignition[1082]: INFO : Ignition 2.22.0 Sep 12 05:53:22.102906 ignition[1082]: INFO : Stage: umount Sep 12 05:53:22.104797 ignition[1082]: INFO : no configs at "/usr/lib/ignition/base.d" Sep 12 05:53:22.104797 ignition[1082]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Sep 12 05:53:22.104797 ignition[1082]: INFO : umount: umount passed Sep 12 05:53:22.104797 ignition[1082]: INFO : Ignition finished successfully Sep 12 05:53:22.110565 systemd[1]: ignition-mount.service: Deactivated successfully. Sep 12 05:53:22.110719 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Sep 12 05:53:22.112833 systemd[1]: Stopped target network.target - Network. Sep 12 05:53:22.114401 systemd[1]: ignition-disks.service: Deactivated successfully. Sep 12 05:53:22.114459 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Sep 12 05:53:22.116190 systemd[1]: ignition-kargs.service: Deactivated successfully. Sep 12 05:53:22.116238 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Sep 12 05:53:22.117147 systemd[1]: ignition-setup.service: Deactivated successfully. Sep 12 05:53:22.117202 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Sep 12 05:53:22.117609 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Sep 12 05:53:22.117650 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Sep 12 05:53:22.118045 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Sep 12 05:53:22.118341 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Sep 12 05:53:22.129854 systemd[1]: systemd-resolved.service: Deactivated successfully. Sep 12 05:53:22.130000 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Sep 12 05:53:22.133572 systemd[1]: sysroot-boot.service: Deactivated successfully. Sep 12 05:53:22.133738 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Sep 12 05:53:22.137725 systemd[1]: initrd-setup-root.service: Deactivated successfully. Sep 12 05:53:22.137845 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Sep 12 05:53:22.138831 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Sep 12 05:53:22.138886 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Sep 12 05:53:22.146993 systemd[1]: systemd-networkd.service: Deactivated successfully. Sep 12 05:53:22.148219 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Sep 12 05:53:22.150667 systemd[1]: Stopped target network-pre.target - Preparation for Network. Sep 12 05:53:22.150772 systemd[1]: systemd-networkd.socket: Deactivated successfully. Sep 12 05:53:22.150817 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Sep 12 05:53:22.156005 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Sep 12 05:53:22.157801 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Sep 12 05:53:22.157872 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Sep 12 05:53:22.160100 systemd[1]: systemd-sysctl.service: Deactivated successfully. Sep 12 05:53:22.160171 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Sep 12 05:53:22.163961 systemd[1]: systemd-modules-load.service: Deactivated successfully. Sep 12 05:53:22.164020 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Sep 12 05:53:22.167096 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Sep 12 05:53:22.175007 systemd[1]: systemd-udevd.service: Deactivated successfully. Sep 12 05:53:22.175238 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Sep 12 05:53:22.178951 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Sep 12 05:53:22.179064 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Sep 12 05:53:22.180386 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Sep 12 05:53:22.180430 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Sep 12 05:53:22.184163 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Sep 12 05:53:22.184222 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Sep 12 05:53:22.188323 systemd[1]: dracut-cmdline.service: Deactivated successfully. Sep 12 05:53:22.188394 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Sep 12 05:53:22.191211 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Sep 12 05:53:22.191270 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Sep 12 05:53:22.196011 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Sep 12 05:53:22.197089 systemd[1]: systemd-network-generator.service: Deactivated successfully. Sep 12 05:53:22.197165 systemd[1]: Stopped systemd-network-generator.service - Generate network units from Kernel command line. Sep 12 05:53:22.200623 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Sep 12 05:53:22.200679 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Sep 12 05:53:22.205205 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Sep 12 05:53:22.205260 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Sep 12 05:53:22.208930 systemd[1]: network-cleanup.service: Deactivated successfully. Sep 12 05:53:22.215251 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Sep 12 05:53:22.224918 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Sep 12 05:53:22.225051 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Sep 12 05:53:22.226308 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Sep 12 05:53:22.229184 systemd[1]: Starting initrd-switch-root.service - Switch Root... Sep 12 05:53:22.263069 systemd[1]: Switching root. Sep 12 05:53:22.308062 systemd-journald[220]: Journal stopped Sep 12 05:53:23.209391 systemd-journald[220]: Received SIGTERM from PID 1 (systemd). Sep 12 05:53:23.209472 kernel: SELinux: policy capability network_peer_controls=1 Sep 12 05:53:23.209487 kernel: SELinux: policy capability open_perms=1 Sep 12 05:53:23.209501 kernel: SELinux: policy capability extended_socket_class=1 Sep 12 05:53:23.209513 kernel: SELinux: policy capability always_check_network=0 Sep 12 05:53:23.209531 kernel: SELinux: policy capability cgroup_seclabel=1 Sep 12 05:53:23.209543 kernel: SELinux: policy capability nnp_nosuid_transition=1 Sep 12 05:53:23.209554 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Sep 12 05:53:23.209578 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Sep 12 05:53:23.209591 kernel: SELinux: policy capability userspace_initial_context=0 Sep 12 05:53:23.209604 kernel: audit: type=1403 audit(1757656402.423:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Sep 12 05:53:23.209619 systemd[1]: Successfully loaded SELinux policy in 65.898ms. Sep 12 05:53:23.209637 systemd[1]: Relabeled /dev/, /dev/shm/, /run/ in 8.543ms. Sep 12 05:53:23.209651 systemd[1]: systemd 256.8 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP -GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE) Sep 12 05:53:23.209663 systemd[1]: Detected virtualization kvm. Sep 12 05:53:23.209675 systemd[1]: Detected architecture x86-64. Sep 12 05:53:23.209687 systemd[1]: Detected first boot. Sep 12 05:53:23.209699 systemd[1]: Initializing machine ID from VM UUID. Sep 12 05:53:23.209711 zram_generator::config[1129]: No configuration found. Sep 12 05:53:23.209734 kernel: Guest personality initialized and is inactive Sep 12 05:53:23.209746 kernel: VMCI host device registered (name=vmci, major=10, minor=125) Sep 12 05:53:23.209760 kernel: Initialized host personality Sep 12 05:53:23.209772 kernel: NET: Registered PF_VSOCK protocol family Sep 12 05:53:23.209784 systemd[1]: Populated /etc with preset unit settings. Sep 12 05:53:23.209797 systemd[1]: run-credentials-systemd\x2djournald.service.mount: Deactivated successfully. Sep 12 05:53:23.209809 systemd[1]: initrd-switch-root.service: Deactivated successfully. Sep 12 05:53:23.209821 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Sep 12 05:53:23.209833 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Sep 12 05:53:23.209846 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Sep 12 05:53:23.209861 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Sep 12 05:53:23.209873 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Sep 12 05:53:23.209885 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Sep 12 05:53:23.209898 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Sep 12 05:53:23.209910 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Sep 12 05:53:23.209922 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Sep 12 05:53:23.209936 systemd[1]: Created slice user.slice - User and Session Slice. Sep 12 05:53:23.209949 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Sep 12 05:53:23.209961 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Sep 12 05:53:23.209973 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Sep 12 05:53:23.209985 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Sep 12 05:53:23.210013 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Sep 12 05:53:23.210026 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Sep 12 05:53:23.210042 systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0... Sep 12 05:53:23.210054 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Sep 12 05:53:23.210067 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Sep 12 05:53:23.210079 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Sep 12 05:53:23.210092 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Sep 12 05:53:23.210117 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Sep 12 05:53:23.210130 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Sep 12 05:53:23.210142 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Sep 12 05:53:23.210154 systemd[1]: Reached target remote-fs.target - Remote File Systems. Sep 12 05:53:23.210170 systemd[1]: Reached target slices.target - Slice Units. Sep 12 05:53:23.210182 systemd[1]: Reached target swap.target - Swaps. Sep 12 05:53:23.210194 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Sep 12 05:53:23.210207 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Sep 12 05:53:23.210219 systemd[1]: Listening on systemd-creds.socket - Credential Encryption/Decryption. Sep 12 05:53:23.210231 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Sep 12 05:53:23.210243 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Sep 12 05:53:23.210255 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Sep 12 05:53:23.210267 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Sep 12 05:53:23.210279 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Sep 12 05:53:23.210301 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Sep 12 05:53:23.210314 systemd[1]: Mounting media.mount - External Media Directory... Sep 12 05:53:23.210326 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:23.210338 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Sep 12 05:53:23.210350 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Sep 12 05:53:23.210362 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Sep 12 05:53:23.210381 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). Sep 12 05:53:23.210393 systemd[1]: Reached target machines.target - Containers. Sep 12 05:53:23.210407 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Sep 12 05:53:23.210420 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Sep 12 05:53:23.210432 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Sep 12 05:53:23.210444 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Sep 12 05:53:23.210456 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Sep 12 05:53:23.210470 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Sep 12 05:53:23.210482 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Sep 12 05:53:23.210494 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Sep 12 05:53:23.210508 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Sep 12 05:53:23.210521 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Sep 12 05:53:23.210540 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Sep 12 05:53:23.210552 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Sep 12 05:53:23.210564 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Sep 12 05:53:23.210582 systemd[1]: Stopped systemd-fsck-usr.service. Sep 12 05:53:23.210595 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). Sep 12 05:53:23.210607 systemd[1]: Starting systemd-journald.service - Journal Service... Sep 12 05:53:23.210619 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Sep 12 05:53:23.210633 kernel: loop: module loaded Sep 12 05:53:23.210645 kernel: fuse: init (API version 7.41) Sep 12 05:53:23.210656 kernel: ACPI: bus type drm_connector registered Sep 12 05:53:23.210668 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Sep 12 05:53:23.210680 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Sep 12 05:53:23.210693 systemd[1]: Starting systemd-udev-load-credentials.service - Load udev Rules from Credentials... Sep 12 05:53:23.210705 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Sep 12 05:53:23.210723 systemd[1]: verity-setup.service: Deactivated successfully. Sep 12 05:53:23.210735 systemd[1]: Stopped verity-setup.service. Sep 12 05:53:23.210769 systemd-journald[1199]: Collecting audit messages is disabled. Sep 12 05:53:23.210792 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:23.210805 systemd-journald[1199]: Journal started Sep 12 05:53:23.210830 systemd-journald[1199]: Runtime Journal (/run/log/journal/14c0f2d84eb447c59efe498951c6fef9) is 6M, max 48.6M, 42.5M free. Sep 12 05:53:22.962329 systemd[1]: Queued start job for default target multi-user.target. Sep 12 05:53:22.984177 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Sep 12 05:53:22.984623 systemd[1]: systemd-journald.service: Deactivated successfully. Sep 12 05:53:23.214967 systemd[1]: Started systemd-journald.service - Journal Service. Sep 12 05:53:23.216666 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Sep 12 05:53:23.217960 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Sep 12 05:53:23.219226 systemd[1]: Mounted media.mount - External Media Directory. Sep 12 05:53:23.220335 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Sep 12 05:53:23.221580 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Sep 12 05:53:23.222846 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Sep 12 05:53:23.224179 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Sep 12 05:53:23.225677 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Sep 12 05:53:23.227243 systemd[1]: modprobe@configfs.service: Deactivated successfully. Sep 12 05:53:23.227517 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Sep 12 05:53:23.229100 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Sep 12 05:53:23.229553 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Sep 12 05:53:23.230981 systemd[1]: modprobe@drm.service: Deactivated successfully. Sep 12 05:53:23.231227 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Sep 12 05:53:23.232691 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Sep 12 05:53:23.232913 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Sep 12 05:53:23.234444 systemd[1]: modprobe@fuse.service: Deactivated successfully. Sep 12 05:53:23.234669 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Sep 12 05:53:23.236071 systemd[1]: modprobe@loop.service: Deactivated successfully. Sep 12 05:53:23.236301 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Sep 12 05:53:23.237776 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Sep 12 05:53:23.239261 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Sep 12 05:53:23.241014 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Sep 12 05:53:23.242604 systemd[1]: Finished systemd-udev-load-credentials.service - Load udev Rules from Credentials. Sep 12 05:53:23.258466 systemd[1]: Reached target network-pre.target - Preparation for Network. Sep 12 05:53:23.261236 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Sep 12 05:53:23.263727 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Sep 12 05:53:23.265011 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Sep 12 05:53:23.265140 systemd[1]: Reached target local-fs.target - Local File Systems. Sep 12 05:53:23.267285 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management. Sep 12 05:53:23.272217 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Sep 12 05:53:23.275373 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Sep 12 05:53:23.277185 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Sep 12 05:53:23.280494 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Sep 12 05:53:23.281767 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Sep 12 05:53:23.284016 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Sep 12 05:53:23.285259 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Sep 12 05:53:23.289229 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Sep 12 05:53:23.294464 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Sep 12 05:53:23.296779 systemd-journald[1199]: Time spent on flushing to /var/log/journal/14c0f2d84eb447c59efe498951c6fef9 is 27.064ms for 947 entries. Sep 12 05:53:23.296779 systemd-journald[1199]: System Journal (/var/log/journal/14c0f2d84eb447c59efe498951c6fef9) is 8M, max 195.6M, 187.6M free. Sep 12 05:53:23.340180 systemd-journald[1199]: Received client request to flush runtime journal. Sep 12 05:53:23.340224 kernel: loop0: detected capacity change from 0 to 128016 Sep 12 05:53:23.298241 systemd[1]: Starting systemd-sysusers.service - Create System Users... Sep 12 05:53:23.301763 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Sep 12 05:53:23.305950 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Sep 12 05:53:23.317502 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Sep 12 05:53:23.319705 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Sep 12 05:53:23.324361 systemd[1]: Starting systemd-machine-id-commit.service - Save Transient machine-id to Disk... Sep 12 05:53:23.330503 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Sep 12 05:53:23.334322 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Sep 12 05:53:23.341657 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Sep 12 05:53:23.361211 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Sep 12 05:53:23.363711 systemd[1]: Finished systemd-machine-id-commit.service - Save Transient machine-id to Disk. Sep 12 05:53:23.374468 systemd[1]: Finished systemd-sysusers.service - Create System Users. Sep 12 05:53:23.378355 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Sep 12 05:53:23.392166 kernel: loop1: detected capacity change from 0 to 110984 Sep 12 05:53:23.409145 systemd-tmpfiles[1265]: ACLs are not supported, ignoring. Sep 12 05:53:23.409165 systemd-tmpfiles[1265]: ACLs are not supported, ignoring. Sep 12 05:53:23.414574 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Sep 12 05:53:23.424141 kernel: loop2: detected capacity change from 0 to 128016 Sep 12 05:53:23.438814 kernel: loop3: detected capacity change from 0 to 110984 Sep 12 05:53:23.447963 (sd-merge)[1271]: Using extensions 'containerd-flatcar', 'docker-flatcar'. Sep 12 05:53:23.448487 (sd-merge)[1271]: Merged extensions into '/usr'. Sep 12 05:53:23.453532 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Sep 12 05:53:23.456567 systemd[1]: Starting ensure-sysext.service... Sep 12 05:53:23.459320 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Sep 12 05:53:23.476946 systemd[1]: Reload requested from client PID 1273 ('systemctl') (unit ensure-sysext.service)... Sep 12 05:53:23.477088 systemd[1]: Reloading... Sep 12 05:53:23.483841 systemd-tmpfiles[1274]: /usr/lib/tmpfiles.d/nfs-utils.conf:6: Duplicate line for path "/var/lib/nfs/sm", ignoring. Sep 12 05:53:23.483881 systemd-tmpfiles[1274]: /usr/lib/tmpfiles.d/nfs-utils.conf:7: Duplicate line for path "/var/lib/nfs/sm.bak", ignoring. Sep 12 05:53:23.484245 systemd-tmpfiles[1274]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Sep 12 05:53:23.484511 systemd-tmpfiles[1274]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Sep 12 05:53:23.485464 systemd-tmpfiles[1274]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Sep 12 05:53:23.485743 systemd-tmpfiles[1274]: ACLs are not supported, ignoring. Sep 12 05:53:23.485819 systemd-tmpfiles[1274]: ACLs are not supported, ignoring. Sep 12 05:53:23.490324 systemd-tmpfiles[1274]: Detected autofs mount point /boot during canonicalization of boot. Sep 12 05:53:23.490338 systemd-tmpfiles[1274]: Skipping /boot Sep 12 05:53:23.502308 systemd-tmpfiles[1274]: Detected autofs mount point /boot during canonicalization of boot. Sep 12 05:53:23.502421 systemd-tmpfiles[1274]: Skipping /boot Sep 12 05:53:23.563175 zram_generator::config[1298]: No configuration found. Sep 12 05:53:23.861678 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Sep 12 05:53:23.861894 systemd[1]: Reloading finished in 384 ms. Sep 12 05:53:23.927669 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Sep 12 05:53:23.933509 ldconfig[1242]: /sbin/ldconfig: /usr/lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Sep 12 05:53:23.956427 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Sep 12 05:53:23.967211 systemd[1]: Starting audit-rules.service - Load Audit Rules... Sep 12 05:53:23.969788 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Sep 12 05:53:23.974595 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Sep 12 05:53:23.981306 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Sep 12 05:53:23.986454 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Sep 12 05:53:23.992139 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:23.993424 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Sep 12 05:53:23.995425 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Sep 12 05:53:23.997734 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Sep 12 05:53:24.000414 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Sep 12 05:53:24.001836 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Sep 12 05:53:24.001942 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). Sep 12 05:53:24.007451 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Sep 12 05:53:24.008616 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:24.014787 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:24.015378 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Sep 12 05:53:24.015626 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Sep 12 05:53:24.015778 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). Sep 12 05:53:24.015922 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:24.017830 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Sep 12 05:53:24.020681 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Sep 12 05:53:24.026753 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Sep 12 05:53:24.027509 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Sep 12 05:53:24.029796 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Sep 12 05:53:24.030421 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Sep 12 05:53:24.032498 systemd[1]: modprobe@loop.service: Deactivated successfully. Sep 12 05:53:24.033017 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Sep 12 05:53:24.044215 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:24.044566 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Sep 12 05:53:24.046468 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Sep 12 05:53:24.049018 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Sep 12 05:53:24.053334 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Sep 12 05:53:24.059604 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Sep 12 05:53:24.060912 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Sep 12 05:53:24.061034 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). Sep 12 05:53:24.061203 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Sep 12 05:53:24.062953 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Sep 12 05:53:24.063696 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Sep 12 05:53:24.064439 systemd[1]: modprobe@drm.service: Deactivated successfully. Sep 12 05:53:24.064746 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Sep 12 05:53:24.068075 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Sep 12 05:53:24.068383 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Sep 12 05:53:24.070163 systemd[1]: Finished ensure-sysext.service. Sep 12 05:53:24.071712 systemd[1]: modprobe@loop.service: Deactivated successfully. Sep 12 05:53:24.072088 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Sep 12 05:53:24.074626 systemd[1]: Started systemd-userdbd.service - User Database Manager. Sep 12 05:53:24.080560 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Sep 12 05:53:24.081198 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Sep 12 05:53:24.092565 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Sep 12 05:53:24.094357 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Sep 12 05:53:24.095149 augenrules[1388]: No rules Sep 12 05:53:24.096093 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Sep 12 05:53:24.099217 systemd[1]: audit-rules.service: Deactivated successfully. Sep 12 05:53:24.099498 systemd[1]: Finished audit-rules.service - Load Audit Rules. Sep 12 05:53:24.111567 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Sep 12 05:53:24.114248 systemd[1]: Starting systemd-update-done.service - Update is Completed... Sep 12 05:53:24.115321 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). Sep 12 05:53:24.128352 systemd[1]: Finished systemd-update-done.service - Update is Completed. Sep 12 05:53:24.150898 systemd-udevd[1398]: Using default interface naming scheme 'v255'. Sep 12 05:53:24.163530 systemd-resolved[1344]: Positive Trust Anchors: Sep 12 05:53:24.163553 systemd-resolved[1344]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Sep 12 05:53:24.163583 systemd-resolved[1344]: 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 Sep 12 05:53:24.167600 systemd-resolved[1344]: Defaulting to hostname 'linux'. Sep 12 05:53:24.169318 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Sep 12 05:53:24.170582 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Sep 12 05:53:24.171806 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Sep 12 05:53:24.176303 systemd[1]: Starting systemd-networkd.service - Network Configuration... Sep 12 05:53:24.181088 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Sep 12 05:53:24.182723 systemd[1]: Reached target sysinit.target - System Initialization. Sep 12 05:53:24.184220 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Sep 12 05:53:24.185778 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Sep 12 05:53:24.187315 systemd[1]: Started google-oslogin-cache.timer - NSS cache refresh timer. Sep 12 05:53:24.188966 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Sep 12 05:53:24.190238 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Sep 12 05:53:24.190265 systemd[1]: Reached target paths.target - Path Units. Sep 12 05:53:24.191385 systemd[1]: Reached target time-set.target - System Time Set. Sep 12 05:53:24.192781 systemd[1]: Started logrotate.timer - Daily rotation of log files. Sep 12 05:53:24.203417 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Sep 12 05:53:24.206184 systemd[1]: Reached target timers.target - Timer Units. Sep 12 05:53:24.208021 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Sep 12 05:53:24.210908 systemd[1]: Starting docker.socket - Docker Socket for the API... Sep 12 05:53:24.217603 systemd[1]: Listening on sshd-unix-local.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_UNIX Local). Sep 12 05:53:24.219187 systemd[1]: Listening on sshd-vsock.socket - OpenSSH Server Socket (systemd-ssh-generator, AF_VSOCK). Sep 12 05:53:24.220546 systemd[1]: Reached target ssh-access.target - SSH Access Available. Sep 12 05:53:24.355386 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Sep 12 05:53:24.356936 systemd[1]: Listening on systemd-hostnamed.socket - Hostname Service Socket. Sep 12 05:53:24.359135 systemd[1]: Listening on docker.socket - Docker Socket for the API. Sep 12 05:53:24.366770 systemd[1]: Reached target sockets.target - Socket Units. Sep 12 05:53:24.367790 systemd[1]: Reached target basic.target - Basic System. Sep 12 05:53:24.368942 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Sep 12 05:53:24.368980 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Sep 12 05:53:24.373926 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Sep 12 05:53:24.376602 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Sep 12 05:53:24.380263 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Sep 12 05:53:24.384330 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Sep 12 05:53:24.386828 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). Sep 12 05:53:24.388627 systemd[1]: Starting google-oslogin-cache.service - NSS cache refresh... Sep 12 05:53:24.390772 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Sep 12 05:53:24.394066 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Sep 12 05:53:24.400612 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Sep 12 05:53:24.404957 jq[1434]: false Sep 12 05:53:24.411275 systemd[1]: Starting systemd-logind.service - User Login Management... Sep 12 05:53:24.413460 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Refreshing passwd entry cache Sep 12 05:53:24.414493 oslogin_cache_refresh[1437]: Refreshing passwd entry cache Sep 12 05:53:24.418957 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Failure getting users, quitting Sep 12 05:53:24.418957 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Produced empty passwd cache file, removing /etc/oslogin_passwd.cache.bak. Sep 12 05:53:24.418946 oslogin_cache_refresh[1437]: Failure getting users, quitting Sep 12 05:53:24.419146 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Refreshing group entry cache Sep 12 05:53:24.418963 oslogin_cache_refresh[1437]: Produced empty passwd cache file, removing /etc/oslogin_passwd.cache.bak. Sep 12 05:53:24.419013 oslogin_cache_refresh[1437]: Refreshing group entry cache Sep 12 05:53:24.419471 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Failure getting groups, quitting Sep 12 05:53:24.419471 google_oslogin_nss_cache[1437]: oslogin_cache_refresh[1437]: Produced empty group cache file, removing /etc/oslogin_group.cache.bak. Sep 12 05:53:24.419463 oslogin_cache_refresh[1437]: Failure getting groups, quitting Sep 12 05:53:24.419473 oslogin_cache_refresh[1437]: Produced empty group cache file, removing /etc/oslogin_group.cache.bak. Sep 12 05:53:24.458866 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Sep 12 05:53:24.463660 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Sep 12 05:53:24.465350 systemd[1]: Starting update-engine.service - Update Engine... Sep 12 05:53:24.466697 extend-filesystems[1435]: Found /dev/vda6 Sep 12 05:53:24.469025 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Sep 12 05:53:24.483423 extend-filesystems[1435]: Found /dev/vda9 Sep 12 05:53:24.488646 extend-filesystems[1435]: Checking size of /dev/vda9 Sep 12 05:53:24.491727 update_engine[1448]: I20250912 05:53:24.491643 1448 main.cc:92] Flatcar Update Engine starting Sep 12 05:53:24.492463 jq[1449]: true Sep 12 05:53:24.511164 extend-filesystems[1435]: Old size kept for /dev/vda9 Sep 12 05:53:24.519472 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Sep 12 05:53:24.521367 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Sep 12 05:53:24.521724 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Sep 12 05:53:24.522241 systemd[1]: extend-filesystems.service: Deactivated successfully. Sep 12 05:53:24.522912 systemd-networkd[1411]: lo: Link UP Sep 12 05:53:24.522960 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Sep 12 05:53:24.524466 systemd[1]: google-oslogin-cache.service: Deactivated successfully. Sep 12 05:53:24.524736 systemd[1]: Finished google-oslogin-cache.service - NSS cache refresh. Sep 12 05:53:24.525798 systemd-networkd[1411]: lo: Gained carrier Sep 12 05:53:24.526678 systemd[1]: motdgen.service: Deactivated successfully. Sep 12 05:53:24.526939 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Sep 12 05:53:24.528487 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Sep 12 05:53:24.528737 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Sep 12 05:53:24.531383 systemd-networkd[1411]: Enumeration completed Sep 12 05:53:24.531527 systemd[1]: Started systemd-networkd.service - Network Configuration. Sep 12 05:53:24.538562 systemd-networkd[1411]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Sep 12 05:53:24.538660 systemd-networkd[1411]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Sep 12 05:53:24.540925 systemd-networkd[1411]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Sep 12 05:53:24.540959 systemd-networkd[1411]: eth0: Link UP Sep 12 05:53:24.541424 systemd-networkd[1411]: eth0: Gained carrier Sep 12 05:53:24.541882 systemd-networkd[1411]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Sep 12 05:53:24.551691 jq[1469]: true Sep 12 05:53:24.554162 systemd-networkd[1411]: eth0: DHCPv4 address 10.0.0.69/16, gateway 10.0.0.1 acquired from 10.0.0.1 Sep 12 05:53:24.555581 systemd-timesyncd[1389]: Network configuration changed, trying to establish connection. Sep 12 05:53:25.245825 systemd-timesyncd[1389]: Contacted time server 10.0.0.1:123 (10.0.0.1). Sep 12 05:53:25.246156 systemd-resolved[1344]: Clock change detected. Flushing caches. Sep 12 05:53:25.246226 systemd-timesyncd[1389]: Initial clock synchronization to Fri 2025-09-12 05:53:25.245751 UTC. Sep 12 05:53:25.247059 systemd[1]: Condition check resulted in dev-ttyS0.device - /dev/ttyS0 being skipped. Sep 12 05:53:25.250321 systemd[1]: Reached target network.target - Network. Sep 12 05:53:25.252641 systemd[1]: Starting containerd.service - containerd container runtime... Sep 12 05:53:25.255659 systemd[1]: Starting systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd... Sep 12 05:53:25.268730 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Sep 12 05:53:25.309653 systemd[1]: Finished systemd-networkd-persistent-storage.service - Enable Persistent Storage in systemd-networkd. Sep 12 05:53:25.320943 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3 Sep 12 05:53:25.322048 dbus-daemon[1431]: [system] SELinux support is enabled Sep 12 05:53:25.322378 systemd-logind[1441]: New seat seat0. Sep 12 05:53:25.323004 (ntainerd)[1504]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR Sep 12 05:53:25.323508 systemd[1]: Started dbus.service - D-Bus System Message Bus. Sep 12 05:53:25.329701 update_engine[1448]: I20250912 05:53:25.329517 1448 update_check_scheduler.cc:74] Next update check in 10m4s Sep 12 05:53:25.330908 systemd[1]: Started systemd-logind.service - User Login Management. Sep 12 05:53:25.332321 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). Sep 12 05:53:25.332354 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Sep 12 05:53:25.334761 dbus-daemon[1431]: [system] Successfully activated service 'org.freedesktop.systemd1' Sep 12 05:53:25.335711 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). Sep 12 05:53:25.335741 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Sep 12 05:53:25.337144 systemd[1]: Started update-engine.service - Update Engine. Sep 12 05:53:25.347686 kernel: i801_smbus 0000:00:1f.3: SMBus using PCI interrupt Sep 12 05:53:25.347988 kernel: i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD Sep 12 05:53:25.352619 kernel: mousedev: PS/2 mouse device common for all mice Sep 12 05:53:25.353828 systemd[1]: Started locksmithd.service - Cluster reboot manager. Sep 12 05:53:25.362555 kernel: ACPI: button: Power Button [PWRF] Sep 12 05:53:25.427952 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Sep 12 05:53:25.433889 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Sep 12 05:53:25.457471 bash[1496]: Updated "/home/core/.ssh/authorized_keys" Sep 12 05:53:25.461201 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Sep 12 05:53:25.463605 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Sep 12 05:53:25.479083 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Sep 12 05:53:25.505043 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Sep 12 05:53:25.520302 systemd-logind[1441]: Watching system buttons on /dev/input/event2 (Power Button) Sep 12 05:53:25.525719 systemd-logind[1441]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) Sep 12 05:53:25.575631 sshd_keygen[1458]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Sep 12 05:53:25.612929 kernel: kvm_amd: TSC scaling supported Sep 12 05:53:25.612999 kernel: kvm_amd: Nested Virtualization enabled Sep 12 05:53:25.613013 kernel: kvm_amd: Nested Paging enabled Sep 12 05:53:25.613045 kernel: kvm_amd: LBR virtualization supported Sep 12 05:53:25.614112 kernel: kvm_amd: Virtual VMLOAD VMSAVE supported Sep 12 05:53:25.614136 kernel: kvm_amd: Virtual GIF supported Sep 12 05:53:25.640188 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Sep 12 05:53:25.646937 systemd[1]: Starting issuegen.service - Generate /run/issue... Sep 12 05:53:25.647275 locksmithd[1510]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Sep 12 05:53:25.667572 kernel: EDAC MC: Ver: 3.0.0 Sep 12 05:53:25.671974 containerd[1504]: time="2025-09-12T05:53:25Z" 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 Sep 12 05:53:25.673006 containerd[1504]: time="2025-09-12T05:53:25.672962473Z" level=info msg="starting containerd" revision=fb4c30d4ede3531652d86197bf3fc9515e5276d9 version=v2.0.5 Sep 12 05:53:25.681595 containerd[1504]: time="2025-09-12T05:53:25.681544851Z" level=warning msg="Configuration migrated from version 2, use `containerd config migrate` to avoid migration" t="9.147µs" Sep 12 05:53:25.681595 containerd[1504]: time="2025-09-12T05:53:25.681583163Z" level=info msg="loading plugin" id=io.containerd.image-verifier.v1.bindir type=io.containerd.image-verifier.v1 Sep 12 05:53:25.681682 containerd[1504]: time="2025-09-12T05:53:25.681601226Z" level=info msg="loading plugin" id=io.containerd.internal.v1.opt type=io.containerd.internal.v1 Sep 12 05:53:25.681862 containerd[1504]: time="2025-09-12T05:53:25.681833161Z" level=info msg="loading plugin" id=io.containerd.warning.v1.deprecations type=io.containerd.warning.v1 Sep 12 05:53:25.681862 containerd[1504]: time="2025-09-12T05:53:25.681854872Z" level=info msg="loading plugin" id=io.containerd.content.v1.content type=io.containerd.content.v1 Sep 12 05:53:25.681902 containerd[1504]: time="2025-09-12T05:53:25.681880951Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 Sep 12 05:53:25.681970 containerd[1504]: time="2025-09-12T05:53:25.681944260Z" level=info msg="skip loading plugin" error="no scratch file generator: skip plugin" id=io.containerd.snapshotter.v1.blockfile type=io.containerd.snapshotter.v1 Sep 12 05:53:25.681970 containerd[1504]: time="2025-09-12T05:53:25.681959328Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.btrfs type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682302 containerd[1504]: time="2025-09-12T05:53:25.682269310Z" 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 Sep 12 05:53:25.682302 containerd[1504]: time="2025-09-12T05:53:25.682291241Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682344 containerd[1504]: time="2025-09-12T05:53:25.682301881Z" level=info msg="skip loading plugin" error="devmapper not configured: skip plugin" id=io.containerd.snapshotter.v1.devmapper type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682344 containerd[1504]: time="2025-09-12T05:53:25.682311158Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.native type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682456 containerd[1504]: time="2025-09-12T05:53:25.682428308Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.overlayfs type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682814 containerd[1504]: time="2025-09-12T05:53:25.682769558Z" level=info msg="loading plugin" id=io.containerd.snapshotter.v1.zfs type=io.containerd.snapshotter.v1 Sep 12 05:53:25.682814 containerd[1504]: time="2025-09-12T05:53:25.682811737Z" 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 Sep 12 05:53:25.682814 containerd[1504]: time="2025-09-12T05:53:25.682822227Z" level=info msg="loading plugin" id=io.containerd.event.v1.exchange type=io.containerd.event.v1 Sep 12 05:53:25.682949 containerd[1504]: time="2025-09-12T05:53:25.682856351Z" level=info msg="loading plugin" id=io.containerd.monitor.task.v1.cgroups type=io.containerd.monitor.task.v1 Sep 12 05:53:25.683119 containerd[1504]: time="2025-09-12T05:53:25.683091081Z" level=info msg="loading plugin" id=io.containerd.metadata.v1.bolt type=io.containerd.metadata.v1 Sep 12 05:53:25.683186 containerd[1504]: time="2025-09-12T05:53:25.683167354Z" level=info msg="metadata content store policy set" policy=shared Sep 12 05:53:25.688688 containerd[1504]: time="2025-09-12T05:53:25.688647613Z" level=info msg="loading plugin" id=io.containerd.gc.v1.scheduler type=io.containerd.gc.v1 Sep 12 05:53:25.688688 containerd[1504]: time="2025-09-12T05:53:25.688689282Z" level=info msg="loading plugin" id=io.containerd.differ.v1.walking type=io.containerd.differ.v1 Sep 12 05:53:25.688750 containerd[1504]: time="2025-09-12T05:53:25.688702176Z" level=info msg="loading plugin" id=io.containerd.lease.v1.manager type=io.containerd.lease.v1 Sep 12 05:53:25.688750 containerd[1504]: time="2025-09-12T05:53:25.688721191Z" level=info msg="loading plugin" id=io.containerd.service.v1.containers-service type=io.containerd.service.v1 Sep 12 05:53:25.688750 containerd[1504]: time="2025-09-12T05:53:25.688738714Z" level=info msg="loading plugin" id=io.containerd.service.v1.content-service type=io.containerd.service.v1 Sep 12 05:53:25.688750 containerd[1504]: time="2025-09-12T05:53:25.688750306Z" level=info msg="loading plugin" id=io.containerd.service.v1.diff-service type=io.containerd.service.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688764613Z" level=info msg="loading plugin" id=io.containerd.service.v1.images-service type=io.containerd.service.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688776455Z" level=info msg="loading plugin" id=io.containerd.service.v1.introspection-service type=io.containerd.service.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688785963Z" level=info msg="loading plugin" id=io.containerd.service.v1.namespaces-service type=io.containerd.service.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688795601Z" level=info msg="loading plugin" id=io.containerd.service.v1.snapshots-service type=io.containerd.service.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688804277Z" level=info msg="loading plugin" id=io.containerd.shim.v1.manager type=io.containerd.shim.v1 Sep 12 05:53:25.688838 containerd[1504]: time="2025-09-12T05:53:25.688816019Z" level=info msg="loading plugin" id=io.containerd.runtime.v2.task type=io.containerd.runtime.v2 Sep 12 05:53:25.688966 containerd[1504]: time="2025-09-12T05:53:25.688945813Z" level=info msg="loading plugin" id=io.containerd.service.v1.tasks-service type=io.containerd.service.v1 Sep 12 05:53:25.688990 containerd[1504]: time="2025-09-12T05:53:25.688968946Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.containers type=io.containerd.grpc.v1 Sep 12 05:53:25.688990 containerd[1504]: time="2025-09-12T05:53:25.688983273Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.content type=io.containerd.grpc.v1 Sep 12 05:53:25.689026 containerd[1504]: time="2025-09-12T05:53:25.689001547Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.diff type=io.containerd.grpc.v1 Sep 12 05:53:25.689026 containerd[1504]: time="2025-09-12T05:53:25.689012788Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.events type=io.containerd.grpc.v1 Sep 12 05:53:25.689026 containerd[1504]: time="2025-09-12T05:53:25.689022927Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.images type=io.containerd.grpc.v1 Sep 12 05:53:25.689092 containerd[1504]: time="2025-09-12T05:53:25.689034970Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.introspection type=io.containerd.grpc.v1 Sep 12 05:53:25.689092 containerd[1504]: time="2025-09-12T05:53:25.689045630Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.leases type=io.containerd.grpc.v1 Sep 12 05:53:25.689092 containerd[1504]: time="2025-09-12T05:53:25.689056180Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.namespaces type=io.containerd.grpc.v1 Sep 12 05:53:25.689092 containerd[1504]: time="2025-09-12T05:53:25.689066589Z" level=info msg="loading plugin" id=io.containerd.sandbox.store.v1.local type=io.containerd.sandbox.store.v1 Sep 12 05:53:25.689092 containerd[1504]: time="2025-09-12T05:53:25.689086927Z" level=info msg="loading plugin" id=io.containerd.cri.v1.images type=io.containerd.cri.v1 Sep 12 05:53:25.689193 containerd[1504]: time="2025-09-12T05:53:25.689152090Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\" for snapshotter \"overlayfs\"" Sep 12 05:53:25.689193 containerd[1504]: time="2025-09-12T05:53:25.689165705Z" level=info msg="Start snapshots syncer" Sep 12 05:53:25.689236 containerd[1504]: time="2025-09-12T05:53:25.689197064Z" level=info msg="loading plugin" id=io.containerd.cri.v1.runtime type=io.containerd.cri.v1 Sep 12 05:53:25.690196 containerd[1504]: time="2025-09-12T05:53:25.689993478Z" 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\"}" Sep 12 05:53:25.690196 containerd[1504]: time="2025-09-12T05:53:25.690130074Z" level=info msg="loading plugin" id=io.containerd.podsandbox.controller.v1.podsandbox type=io.containerd.podsandbox.controller.v1 Sep 12 05:53:25.692180 containerd[1504]: time="2025-09-12T05:53:25.691776172Z" level=info msg="loading plugin" id=io.containerd.sandbox.controller.v1.shim type=io.containerd.sandbox.controller.v1 Sep 12 05:53:25.692497 containerd[1504]: time="2025-09-12T05:53:25.692474652Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandbox-controllers type=io.containerd.grpc.v1 Sep 12 05:53:25.692606 containerd[1504]: time="2025-09-12T05:53:25.692590870Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.sandboxes type=io.containerd.grpc.v1 Sep 12 05:53:25.692666 containerd[1504]: time="2025-09-12T05:53:25.692654048Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.snapshots type=io.containerd.grpc.v1 Sep 12 05:53:25.692721 containerd[1504]: time="2025-09-12T05:53:25.692708951Z" level=info msg="loading plugin" id=io.containerd.streaming.v1.manager type=io.containerd.streaming.v1 Sep 12 05:53:25.692779 containerd[1504]: time="2025-09-12T05:53:25.692766930Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.streaming type=io.containerd.grpc.v1 Sep 12 05:53:25.692833 containerd[1504]: time="2025-09-12T05:53:25.692821623Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.tasks type=io.containerd.grpc.v1 Sep 12 05:53:25.692889 containerd[1504]: time="2025-09-12T05:53:25.692877578Z" level=info msg="loading plugin" id=io.containerd.transfer.v1.local type=io.containerd.transfer.v1 Sep 12 05:53:25.692981 containerd[1504]: time="2025-09-12T05:53:25.692966645Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.transfer type=io.containerd.grpc.v1 Sep 12 05:53:25.693037 containerd[1504]: time="2025-09-12T05:53:25.693025465Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.version type=io.containerd.grpc.v1 Sep 12 05:53:25.693093 containerd[1504]: time="2025-09-12T05:53:25.693081370Z" level=info msg="loading plugin" id=io.containerd.monitor.container.v1.restart type=io.containerd.monitor.container.v1 Sep 12 05:53:25.693191 containerd[1504]: time="2025-09-12T05:53:25.693177510Z" level=info msg="loading plugin" id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 Sep 12 05:53:25.693269 containerd[1504]: time="2025-09-12T05:53:25.693253312Z" 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 Sep 12 05:53:25.693321 containerd[1504]: time="2025-09-12T05:53:25.693308776Z" level=info msg="loading plugin" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 Sep 12 05:53:25.693397 containerd[1504]: time="2025-09-12T05:53:25.693369931Z" level=info msg="skip loading plugin" error="skip plugin: tracing endpoint not configured" id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693438740Z" level=info msg="loading plugin" id=io.containerd.ttrpc.v1.otelttrpc type=io.containerd.ttrpc.v1 Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693455081Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.healthcheck type=io.containerd.grpc.v1 Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693477673Z" level=info msg="loading plugin" id=io.containerd.nri.v1.nri type=io.containerd.nri.v1 Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693501528Z" level=info msg="runtime interface created" Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693508000Z" level=info msg="created NRI interface" Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693522798Z" level=info msg="loading plugin" id=io.containerd.grpc.v1.cri type=io.containerd.grpc.v1 Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693560729Z" level=info msg="Connect containerd service" Sep 12 05:53:25.693679 containerd[1504]: time="2025-09-12T05:53:25.693602247Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Sep 12 05:53:25.694818 containerd[1504]: time="2025-09-12T05:53:25.694793111Z" 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" Sep 12 05:53:25.700959 systemd[1]: issuegen.service: Deactivated successfully. Sep 12 05:53:25.701267 systemd[1]: Finished issuegen.service - Generate /run/issue. Sep 12 05:53:25.707165 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Sep 12 05:53:25.738937 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Sep 12 05:53:25.765845 systemd[1]: Started getty@tty1.service - Getty on tty1. Sep 12 05:53:25.767580 systemd[1]: Started serial-getty@ttyS0.service - Serial Getty on ttyS0. Sep 12 05:53:25.768841 systemd[1]: Reached target getty.target - Login Prompts. Sep 12 05:53:25.771190 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Sep 12 05:53:25.779469 containerd[1504]: time="2025-09-12T05:53:25.779407052Z" level=info msg="Start subscribing containerd event" Sep 12 05:53:25.779553 containerd[1504]: time="2025-09-12T05:53:25.779496780Z" level=info msg="Start recovering state" Sep 12 05:53:25.779656 containerd[1504]: time="2025-09-12T05:53:25.779630682Z" level=info msg="Start event monitor" Sep 12 05:53:25.779695 containerd[1504]: time="2025-09-12T05:53:25.779659766Z" level=info msg="Start cni network conf syncer for default" Sep 12 05:53:25.779695 containerd[1504]: time="2025-09-12T05:53:25.779668743Z" level=info msg="Start streaming server" Sep 12 05:53:25.779695 containerd[1504]: time="2025-09-12T05:53:25.779678401Z" level=info msg="Registered namespace \"k8s.io\" with NRI" Sep 12 05:53:25.779769 containerd[1504]: time="2025-09-12T05:53:25.779681096Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Sep 12 05:53:25.779769 containerd[1504]: time="2025-09-12T05:53:25.779753833Z" level=info msg=serving... address=/run/containerd/containerd.sock Sep 12 05:53:25.779813 containerd[1504]: time="2025-09-12T05:53:25.779687198Z" level=info msg="runtime interface starting up..." Sep 12 05:53:25.779813 containerd[1504]: time="2025-09-12T05:53:25.779794279Z" level=info msg="starting plugins..." Sep 12 05:53:25.779850 containerd[1504]: time="2025-09-12T05:53:25.779816150Z" level=info msg="Synchronizing NRI (plugin) with current runtime state" Sep 12 05:53:25.780092 containerd[1504]: time="2025-09-12T05:53:25.779946574Z" level=info msg="containerd successfully booted in 0.108497s" Sep 12 05:53:25.780014 systemd[1]: Started containerd.service - containerd container runtime. Sep 12 05:53:27.184905 systemd-networkd[1411]: eth0: Gained IPv6LL Sep 12 05:53:27.188445 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Sep 12 05:53:27.190359 systemd[1]: Reached target network-online.target - Network is Online. Sep 12 05:53:27.193318 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Sep 12 05:53:27.195475 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Sep 12 05:53:27.238040 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Sep 12 05:53:27.259943 systemd[1]: coreos-metadata.service: Deactivated successfully. Sep 12 05:53:27.260228 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Sep 12 05:53:27.263199 systemd[1]: Starting etcd-member.service - etcd (System Application Container)... Sep 12 05:53:27.264365 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Sep 12 05:53:27.286438 (-wrapper)[1588]: etcd-member.service: Referenced but unset environment variable evaluates to an empty string: ETCD_OPTS Sep 12 05:53:27.465357 systemd[1]: Starting docker.service - Docker Application Container Engine... Sep 12 05:53:27.491045 (dockerd)[1600]: 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 Sep 12 05:53:28.072294 dockerd[1600]: time="2025-09-12T05:53:28.072205356Z" level=info msg="Starting up" Sep 12 05:53:28.073197 dockerd[1600]: time="2025-09-12T05:53:28.073143817Z" level=info msg="OTEL tracing is not configured, using no-op tracer provider" Sep 12 05:53:28.094866 dockerd[1600]: time="2025-09-12T05:53:28.094807411Z" level=info msg="Creating a containerd client" address=/var/run/docker/libcontainerd/docker-containerd.sock timeout=1m0s Sep 12 05:53:28.127307 systemd[1]: var-lib-docker-metacopy\x2dcheck3809360960-merged.mount: Deactivated successfully. Sep 12 05:53:28.155549 dockerd[1600]: time="2025-09-12T05:53:28.155486268Z" level=info msg="Loading containers: start." Sep 12 05:53:28.166571 kernel: Initializing XFRM netlink socket Sep 12 05:53:28.451888 systemd-networkd[1411]: docker0: Link UP Sep 12 05:53:28.457156 dockerd[1600]: time="2025-09-12T05:53:28.457108525Z" level=info msg="Loading containers: done." Sep 12 05:53:28.471234 systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck1770719143-merged.mount: Deactivated successfully. Sep 12 05:53:28.473402 dockerd[1600]: time="2025-09-12T05:53:28.473345411Z" 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 Sep 12 05:53:28.473547 dockerd[1600]: time="2025-09-12T05:53:28.473450027Z" level=info msg="Docker daemon" commit=6430e49a55babd9b8f4d08e70ecb2b68900770fe containerd-snapshotter=false storage-driver=overlay2 version=28.0.4 Sep 12 05:53:28.473605 dockerd[1600]: time="2025-09-12T05:53:28.473580271Z" level=info msg="Initializing buildkit" Sep 12 05:53:28.504387 dockerd[1600]: time="2025-09-12T05:53:28.504335880Z" level=info msg="Completed buildkit initialization" Sep 12 05:53:28.508644 dockerd[1600]: time="2025-09-12T05:53:28.508609115Z" level=info msg="Daemon has completed initialization" Sep 12 05:53:28.508739 dockerd[1600]: time="2025-09-12T05:53:28.508682753Z" level=info msg="API listen on /run/docker.sock" Sep 12 05:53:28.508839 systemd[1]: Started docker.service - Docker Application Container Engine. Sep 12 05:53:28.511769 etcd-wrapper[1592]: Error response from daemon: No such container: etcd-member Sep 12 05:53:28.530836 etcd-wrapper[1799]: Error response from daemon: No such container: etcd-member Sep 12 05:53:28.673808 etcd-wrapper[1820]: Unable to find image 'quay.io/coreos/etcd:v3.5.16' locally Sep 12 05:53:29.821547 etcd-wrapper[1820]: v3.5.16: Pulling from coreos/etcd Sep 12 05:53:30.086783 etcd-wrapper[1820]: 804c8aba2cc6: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: 2ae710cd8bfe: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: d462aa345367: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: 0f8b424aa0b9: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: d557676654e5: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: c8022d07192e: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: d858cbc252ad: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: 1069fc2daed1: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: b40161cd83fc: Pulling fs layer Sep 12 05:53:30.086783 etcd-wrapper[1820]: 5318d93a3a65: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: 307c1adadb60: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: fbb01d9e9dc9: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: fbfea02ac3cf: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: 8c26e4bf18e2: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: 1e59a65f8816: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: ffbd4ca5f0bd: Pulling fs layer Sep 12 05:53:30.087115 etcd-wrapper[1820]: d557676654e5: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: c8022d07192e: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: d858cbc252ad: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 1069fc2daed1: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: b40161cd83fc: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 5318d93a3a65: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 307c1adadb60: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: fbb01d9e9dc9: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: fbfea02ac3cf: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 8c26e4bf18e2: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 1e59a65f8816: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: ffbd4ca5f0bd: Waiting Sep 12 05:53:30.087115 etcd-wrapper[1820]: 0f8b424aa0b9: Waiting Sep 12 05:53:30.313990 etcd-wrapper[1820]: 2ae710cd8bfe: Download complete Sep 12 05:53:30.315961 etcd-wrapper[1820]: 804c8aba2cc6: Download complete Sep 12 05:53:30.350617 etcd-wrapper[1820]: 804c8aba2cc6: Pull complete Sep 12 05:53:30.369450 systemd[1]: var-lib-docker-overlay2-eed5ffa1d63018215eade88d29a36f14180e85955cde954709deb7c56f62372c-merged.mount: Deactivated successfully. Sep 12 05:53:30.386832 etcd-wrapper[1820]: 2ae710cd8bfe: Pull complete Sep 12 05:53:30.447152 etcd-wrapper[1820]: d462aa345367: Verifying Checksum Sep 12 05:53:30.447152 etcd-wrapper[1820]: d462aa345367: Download complete Sep 12 05:53:30.592725 etcd-wrapper[1820]: 0f8b424aa0b9: Verifying Checksum Sep 12 05:53:30.592725 etcd-wrapper[1820]: 0f8b424aa0b9: Download complete Sep 12 05:53:30.601398 etcd-wrapper[1820]: d557676654e5: Verifying Checksum Sep 12 05:53:30.601398 etcd-wrapper[1820]: d557676654e5: Download complete Sep 12 05:53:30.659321 etcd-wrapper[1820]: c8022d07192e: Verifying Checksum Sep 12 05:53:30.659430 etcd-wrapper[1820]: c8022d07192e: Download complete Sep 12 05:53:31.629751 etcd-wrapper[1820]: d858cbc252ad: Verifying Checksum Sep 12 05:53:31.629751 etcd-wrapper[1820]: d858cbc252ad: Download complete Sep 12 05:53:31.688207 etcd-wrapper[1820]: 1069fc2daed1: Verifying Checksum Sep 12 05:53:31.688207 etcd-wrapper[1820]: 1069fc2daed1: Download complete Sep 12 05:53:31.763141 etcd-wrapper[1820]: b40161cd83fc: Verifying Checksum Sep 12 05:53:31.763141 etcd-wrapper[1820]: b40161cd83fc: Download complete Sep 12 05:53:31.777391 systemd[1]: var-lib-docker-overlay2-d54334ff35b042e6b99f8c2425bedc7cab7d186db9450c39d16be75abd2d4a73-merged.mount: Deactivated successfully. Sep 12 05:53:31.916806 etcd-wrapper[1820]: 5318d93a3a65: Verifying Checksum Sep 12 05:53:31.916806 etcd-wrapper[1820]: 5318d93a3a65: Download complete Sep 12 05:53:31.997048 etcd-wrapper[1820]: 307c1adadb60: Verifying Checksum Sep 12 05:53:31.997048 etcd-wrapper[1820]: 307c1adadb60: Download complete Sep 12 05:53:32.031442 etcd-wrapper[1820]: fbb01d9e9dc9: Verifying Checksum Sep 12 05:53:32.031442 etcd-wrapper[1820]: fbb01d9e9dc9: Download complete Sep 12 05:53:32.110031 etcd-wrapper[1820]: d462aa345367: Pull complete Sep 12 05:53:32.115045 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Sep 12 05:53:32.117879 systemd[1]: Started sshd@0-10.0.0.69:22-10.0.0.1:41454.service - OpenSSH per-connection server daemon (10.0.0.1:41454). Sep 12 05:53:32.131995 systemd[1]: var-lib-docker-overlay2-dc026bc40f8c8b189042fc46a0fa03ee0790c5fa599750a36a82a2f3da66b5b9-merged.mount: Deactivated successfully. Sep 12 05:53:32.165910 etcd-wrapper[1820]: 0f8b424aa0b9: Pull complete Sep 12 05:53:32.298834 etcd-wrapper[1820]: d557676654e5: Pull complete Sep 12 05:53:32.351568 etcd-wrapper[1820]: 1e59a65f8816: Verifying Checksum Sep 12 05:53:32.351729 etcd-wrapper[1820]: 1e59a65f8816: Download complete Sep 12 05:53:32.373354 etcd-wrapper[1820]: c8022d07192e: Pull complete Sep 12 05:53:32.382900 etcd-wrapper[1820]: 8c26e4bf18e2: Verifying Checksum Sep 12 05:53:32.382900 etcd-wrapper[1820]: 8c26e4bf18e2: Download complete Sep 12 05:53:32.920215 sshd[1855]: Accepted publickey for core from 10.0.0.1 port 41454 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:32.922310 sshd-session[1855]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:32.930460 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Sep 12 05:53:32.933855 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Sep 12 05:53:32.934761 etcd-wrapper[1820]: d858cbc252ad: Pull complete Sep 12 05:53:32.942118 systemd-logind[1441]: New session 1 of user core. Sep 12 05:53:32.953371 systemd[1]: var-lib-docker-overlay2-18e886083f821431161855eddc33b0f7e5e62b59d90c37d1c9baf6ef7d9fd249-merged.mount: Deactivated successfully. Sep 12 05:53:32.954936 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Sep 12 05:53:32.958863 systemd[1]: Starting user@500.service - User Manager for UID 500... Sep 12 05:53:32.968470 etcd-wrapper[1820]: 1069fc2daed1: Pull complete Sep 12 05:53:32.975971 etcd-wrapper[1820]: fbfea02ac3cf: Verifying Checksum Sep 12 05:53:32.975971 etcd-wrapper[1820]: fbfea02ac3cf: Download complete Sep 12 05:53:32.976872 (systemd)[1882]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Sep 12 05:53:32.979473 systemd-logind[1441]: New session c1 of user core. Sep 12 05:53:32.987423 systemd[1]: var-lib-docker-overlay2-bd1f3af8b04bc7a25dae305fd4d1b814ff4a43e00e42b8ad27d9fe0379770309-merged.mount: Deactivated successfully. Sep 12 05:53:33.007230 etcd-wrapper[1820]: b40161cd83fc: Pull complete Sep 12 05:53:33.144082 etcd-wrapper[1820]: 5318d93a3a65: Pull complete Sep 12 05:53:33.174615 etcd-wrapper[1820]: ffbd4ca5f0bd: Verifying Checksum Sep 12 05:53:33.174615 etcd-wrapper[1820]: ffbd4ca5f0bd: Download complete Sep 12 05:53:33.179050 etcd-wrapper[1820]: 307c1adadb60: Pull complete Sep 12 05:53:33.262659 systemd[1882]: Queued start job for default target default.target. Sep 12 05:53:33.288069 systemd[1882]: Created slice app.slice - User Application Slice. Sep 12 05:53:33.288142 systemd[1882]: Reached target paths.target - Paths. Sep 12 05:53:33.288247 systemd[1882]: Reached target timers.target - Timers. Sep 12 05:53:33.291444 systemd[1882]: Starting dbus.socket - D-Bus User Message Bus Socket... Sep 12 05:53:33.318983 systemd[1882]: Listening on dbus.socket - D-Bus User Message Bus Socket. Sep 12 05:53:33.319114 systemd[1882]: Reached target sockets.target - Sockets. Sep 12 05:53:33.319157 systemd[1882]: Reached target basic.target - Basic System. Sep 12 05:53:33.319209 systemd[1882]: Reached target default.target - Main User Target. Sep 12 05:53:33.319250 systemd[1882]: Startup finished in 331ms. Sep 12 05:53:33.319323 systemd[1]: Started user@500.service - User Manager for UID 500. Sep 12 05:53:33.333727 systemd[1]: Started session-1.scope - Session 1 of User core. Sep 12 05:53:33.397960 systemd[1]: Started sshd@1-10.0.0.69:22-10.0.0.1:41458.service - OpenSSH per-connection server daemon (10.0.0.1:41458). Sep 12 05:53:33.465523 etcd-wrapper[1820]: fbb01d9e9dc9: Pull complete Sep 12 05:53:33.469028 sshd[1915]: Accepted publickey for core from 10.0.0.1 port 41458 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:33.471465 sshd-session[1915]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:33.479120 systemd-logind[1441]: New session 2 of user core. Sep 12 05:53:33.488811 systemd[1]: Started session-2.scope - Session 2 of User core. Sep 12 05:53:33.548459 sshd[1922]: Connection closed by 10.0.0.1 port 41458 Sep 12 05:53:33.548890 sshd-session[1915]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:33.558386 systemd[1]: sshd@1-10.0.0.69:22-10.0.0.1:41458.service: Deactivated successfully. Sep 12 05:53:33.560973 systemd[1]: session-2.scope: Deactivated successfully. Sep 12 05:53:33.562813 systemd-logind[1441]: Session 2 logged out. Waiting for processes to exit. Sep 12 05:53:33.566179 systemd[1]: Started sshd@2-10.0.0.69:22-10.0.0.1:41466.service - OpenSSH per-connection server daemon (10.0.0.1:41466). Sep 12 05:53:33.568471 systemd-logind[1441]: Removed session 2. Sep 12 05:53:33.627274 sshd[1928]: Accepted publickey for core from 10.0.0.1 port 41466 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:33.629206 sshd-session[1928]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:33.634205 systemd-logind[1441]: New session 3 of user core. Sep 12 05:53:33.835833 systemd[1]: Started session-3.scope - Session 3 of User core. Sep 12 05:53:33.893714 sshd[1931]: Connection closed by 10.0.0.1 port 41466 Sep 12 05:53:33.894061 sshd-session[1928]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:33.899013 systemd[1]: sshd@2-10.0.0.69:22-10.0.0.1:41466.service: Deactivated successfully. Sep 12 05:53:33.900938 systemd[1]: session-3.scope: Deactivated successfully. Sep 12 05:53:33.901661 systemd-logind[1441]: Session 3 logged out. Waiting for processes to exit. Sep 12 05:53:33.902766 systemd-logind[1441]: Removed session 3. Sep 12 05:53:33.925419 etcd-wrapper[1820]: fbfea02ac3cf: Pull complete Sep 12 05:53:34.020177 systemd[1]: var-lib-docker-overlay2-dba99d42985e8586dfee32f1aa22d1bfa72fec89358b97b02760495fa62be6c6-merged.mount: Deactivated successfully. Sep 12 05:53:34.082711 etcd-wrapper[1820]: 8c26e4bf18e2: Pull complete Sep 12 05:53:34.101445 systemd[1]: var-lib-docker-overlay2-9ae2e9f2c02a59b9ffbb01a0771482f8002fca70433139160db92d65d3773fc3-merged.mount: Deactivated successfully. Sep 12 05:53:34.112876 etcd-wrapper[1820]: 1e59a65f8816: Pull complete Sep 12 05:53:34.140735 etcd-wrapper[1820]: ffbd4ca5f0bd: Pull complete Sep 12 05:53:34.153371 etcd-wrapper[1820]: Digest: sha256:d967d98a12dc220a1a290794711dba7eba04b8ce465e12b02383d1bfbb33e159 Sep 12 05:53:34.157101 etcd-wrapper[1820]: Status: Downloaded newer image for quay.io/coreos/etcd:v3.5.16 Sep 12 05:53:34.240840 containerd[1504]: time="2025-09-12T05:53:34.240741046Z" level=info msg="connecting to shim 3b7d971e91b82fd769b8f7b1db921a47ddd5780e02fcb8d5c7272ade5ebb60ba" address="unix:///run/containerd/s/8667c7505f023109ef9b424707f4d5db5e69372622891f1113cbfbac2114fe1b" namespace=moby protocol=ttrpc version=3 Sep 12 05:53:34.323694 systemd[1]: Started docker-3b7d971e91b82fd769b8f7b1db921a47ddd5780e02fcb8d5c7272ade5ebb60ba.scope - libcontainer container 3b7d971e91b82fd769b8f7b1db921a47ddd5780e02fcb8d5c7272ade5ebb60ba. Sep 12 05:53:34.343043 systemd-resolved[1344]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.424122Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_DATA_DIR","variable-value":"/var/lib/etcd"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.424326Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_NAME","variable-value":"14c0f2d84eb447c59efe498951c6fef9"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424350Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_URL=quay.io/coreos/etcd"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424365Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_TAG=v3.5.16"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424371Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_USER=etcd"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424376Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_SSL_DIR=/etc/ssl/certs"} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424397Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.424436Z","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.69:2379"]} Sep 12 05:53:34.424707 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.424507Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Sep 12 05:53:34.425014 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.424524Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} Sep 12 05:53:34.425608 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.425320Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} Sep 12 05:53:34.425796 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.425605Z","caller":"embed/etcd.go:311","msg":"starting an etcd server","etcd-version":"3.5.16","git-sha":"f20bbad","go-version":"go1.22.7","go-os":"linux","go-arch":"amd64","max-cpu-set":4,"max-cpu-available":4,"member-initialized":false,"name":"14c0f2d84eb447c59efe498951c6fef9","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.69:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"14c0f2d84eb447c59efe498951c6fef9=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"} Sep 12 05:53:34.429623 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.429368Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"3.307174ms"} Sep 12 05:53:34.434414 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434230Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} Sep 12 05:53:34.434414 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434297Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} Sep 12 05:53:34.434414 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434342Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} Sep 12 05:53:34.434630 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434351Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} Sep 12 05:53:34.434630 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434366Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} Sep 12 05:53:34.434630 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.434395Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Sep 12 05:53:34.439635 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:53:34.439422Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} Sep 12 05:53:34.441054 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.440883Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} Sep 12 05:53:34.442010 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.441842Z","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"} Sep 12 05:53:34.442894 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.442685Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} Sep 12 05:53:34.443185 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.442912Z","caller":"etcdserver/server.go:757","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"} Sep 12 05:53:34.443185 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.442956Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Sep 12 05:53:34.443310 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.443058Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} Sep 12 05:53:34.443434 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.443259Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} Sep 12 05:53:34.443508 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.443358Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} Sep 12 05:53:34.444037 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.443867Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Sep 12 05:53:34.446410 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.445465Z","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"]} Sep 12 05:53:34.446410 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.446054Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} Sep 12 05:53:34.446410 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.446090Z","caller":"embed/etcd.go:280","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.69:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} Sep 12 05:53:34.446410 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:34.446089Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235227Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235306Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235351Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235366Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235373Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235382Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} Sep 12 05:53:35.235733 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.235391Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} Sep 12 05:53:35.264658 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.264106Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} Sep 12 05:53:35.293000 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.291976Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:14c0f2d84eb447c59efe498951c6fef9 ClientURLs:[http://10.0.0.69:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} Sep 12 05:53:35.293000 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.291971Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} Sep 12 05:53:35.293000 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.292295Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} Sep 12 05:53:35.293000 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.292509Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} Sep 12 05:53:35.293397 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.292948Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Sep 12 05:53:35.293215 systemd[1]: Started etcd-member.service - etcd (System Application Container). Sep 12 05:53:35.293952 systemd[1]: Reached target multi-user.target - Multi-User System. Sep 12 05:53:35.294634 systemd[1]: Startup finished in 3.295s (kernel) + 4.787s (initrd) + 12.246s (userspace) = 20.329s. Sep 12 05:53:35.294964 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.294298Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} Sep 12 05:53:35.313895 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.311210Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} Sep 12 05:53:35.314139 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.311472Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} Sep 12 05:53:35.314139 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:53:35.311598Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} Sep 12 05:53:43.912522 systemd[1]: Started sshd@3-10.0.0.69:22-10.0.0.1:41802.service - OpenSSH per-connection server daemon (10.0.0.1:41802). Sep 12 05:53:43.979089 sshd[2008]: Accepted publickey for core from 10.0.0.1 port 41802 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:43.980374 sshd-session[2008]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:43.985306 systemd-logind[1441]: New session 4 of user core. Sep 12 05:53:44.004969 systemd[1]: Started session-4.scope - Session 4 of User core. Sep 12 05:53:44.059879 sshd[2011]: Connection closed by 10.0.0.1 port 41802 Sep 12 05:53:44.060253 sshd-session[2008]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.069140 systemd[1]: sshd@3-10.0.0.69:22-10.0.0.1:41802.service: Deactivated successfully. Sep 12 05:53:44.071171 systemd[1]: session-4.scope: Deactivated successfully. Sep 12 05:53:44.071917 systemd-logind[1441]: Session 4 logged out. Waiting for processes to exit. Sep 12 05:53:44.075054 systemd[1]: Started sshd@4-10.0.0.69:22-10.0.0.1:41810.service - OpenSSH per-connection server daemon (10.0.0.1:41810). Sep 12 05:53:44.075641 systemd-logind[1441]: Removed session 4. Sep 12 05:53:44.130793 sshd[2017]: Accepted publickey for core from 10.0.0.1 port 41810 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:44.132595 sshd-session[2017]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:44.137420 systemd-logind[1441]: New session 5 of user core. Sep 12 05:53:44.150689 systemd[1]: Started session-5.scope - Session 5 of User core. Sep 12 05:53:44.201263 sshd[2020]: Connection closed by 10.0.0.1 port 41810 Sep 12 05:53:44.201482 sshd-session[2017]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.216133 systemd[1]: sshd@4-10.0.0.69:22-10.0.0.1:41810.service: Deactivated successfully. Sep 12 05:53:44.218253 systemd[1]: session-5.scope: Deactivated successfully. Sep 12 05:53:44.219087 systemd-logind[1441]: Session 5 logged out. Waiting for processes to exit. Sep 12 05:53:44.222351 systemd[1]: Started sshd@5-10.0.0.69:22-10.0.0.1:41824.service - OpenSSH per-connection server daemon (10.0.0.1:41824). Sep 12 05:53:44.223099 systemd-logind[1441]: Removed session 5. Sep 12 05:53:44.280953 sshd[2026]: Accepted publickey for core from 10.0.0.1 port 41824 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:44.282761 sshd-session[2026]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:44.287740 systemd-logind[1441]: New session 6 of user core. Sep 12 05:53:44.301715 systemd[1]: Started session-6.scope - Session 6 of User core. Sep 12 05:53:44.358531 sshd[2029]: Connection closed by 10.0.0.1 port 41824 Sep 12 05:53:44.359099 sshd-session[2026]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.372761 systemd[1]: sshd@5-10.0.0.69:22-10.0.0.1:41824.service: Deactivated successfully. Sep 12 05:53:44.374930 systemd[1]: session-6.scope: Deactivated successfully. Sep 12 05:53:44.375733 systemd-logind[1441]: Session 6 logged out. Waiting for processes to exit. Sep 12 05:53:44.378935 systemd[1]: Started sshd@6-10.0.0.69:22-10.0.0.1:41836.service - OpenSSH per-connection server daemon (10.0.0.1:41836). Sep 12 05:53:44.379760 systemd-logind[1441]: Removed session 6. Sep 12 05:53:44.438685 sshd[2035]: Accepted publickey for core from 10.0.0.1 port 41836 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:44.440331 sshd-session[2035]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:44.445257 systemd-logind[1441]: New session 7 of user core. Sep 12 05:53:44.455687 systemd[1]: Started session-7.scope - Session 7 of User core. Sep 12 05:53:44.517655 sudo[2040]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/setenforce 1 Sep 12 05:53:44.517999 sudo[2040]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Sep 12 05:53:44.538995 sudo[2040]: pam_unix(sudo:session): session closed for user root Sep 12 05:53:44.541050 sshd[2039]: Connection closed by 10.0.0.1 port 41836 Sep 12 05:53:44.541357 sshd-session[2035]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.557433 systemd[1]: sshd@6-10.0.0.69:22-10.0.0.1:41836.service: Deactivated successfully. Sep 12 05:53:44.559463 systemd[1]: session-7.scope: Deactivated successfully. Sep 12 05:53:44.560274 systemd-logind[1441]: Session 7 logged out. Waiting for processes to exit. Sep 12 05:53:44.563337 systemd[1]: Started sshd@7-10.0.0.69:22-10.0.0.1:41852.service - OpenSSH per-connection server daemon (10.0.0.1:41852). Sep 12 05:53:44.564051 systemd-logind[1441]: Removed session 7. Sep 12 05:53:44.622471 sshd[2046]: Accepted publickey for core from 10.0.0.1 port 41852 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:44.623882 sshd-session[2046]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:44.628577 systemd-logind[1441]: New session 8 of user core. Sep 12 05:53:44.638741 systemd[1]: Started session-8.scope - Session 8 of User core. Sep 12 05:53:44.692089 sudo[2051]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/rm -rf /etc/audit/rules.d/80-selinux.rules /etc/audit/rules.d/99-default.rules Sep 12 05:53:44.692412 sudo[2051]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Sep 12 05:53:44.699115 sudo[2051]: pam_unix(sudo:session): session closed for user root Sep 12 05:53:44.705653 sudo[2050]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/systemctl restart audit-rules Sep 12 05:53:44.705978 sudo[2050]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Sep 12 05:53:44.718661 systemd[1]: Starting audit-rules.service - Load Audit Rules... Sep 12 05:53:44.776050 augenrules[2073]: No rules Sep 12 05:53:44.778241 systemd[1]: audit-rules.service: Deactivated successfully. Sep 12 05:53:44.778657 systemd[1]: Finished audit-rules.service - Load Audit Rules. Sep 12 05:53:44.780219 sudo[2050]: pam_unix(sudo:session): session closed for user root Sep 12 05:53:44.781818 sshd[2049]: Connection closed by 10.0.0.1 port 41852 Sep 12 05:53:44.782148 sshd-session[2046]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.795666 systemd[1]: sshd@7-10.0.0.69:22-10.0.0.1:41852.service: Deactivated successfully. Sep 12 05:53:44.797707 systemd[1]: session-8.scope: Deactivated successfully. Sep 12 05:53:44.798641 systemd-logind[1441]: Session 8 logged out. Waiting for processes to exit. Sep 12 05:53:44.801214 systemd[1]: Started sshd@8-10.0.0.69:22-10.0.0.1:41858.service - OpenSSH per-connection server daemon (10.0.0.1:41858). Sep 12 05:53:44.802025 systemd-logind[1441]: Removed session 8. Sep 12 05:53:44.866081 sshd[2082]: Accepted publickey for core from 10.0.0.1 port 41858 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:44.868234 sshd-session[2082]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:44.873232 systemd-logind[1441]: New session 9 of user core. Sep 12 05:53:44.882698 systemd[1]: Started session-9.scope - Session 9 of User core. Sep 12 05:53:44.933771 sshd[2085]: Connection closed by 10.0.0.1 port 41858 Sep 12 05:53:44.934195 sshd-session[2082]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:44.950071 systemd[1]: sshd@8-10.0.0.69:22-10.0.0.1:41858.service: Deactivated successfully. Sep 12 05:53:44.952057 systemd[1]: session-9.scope: Deactivated successfully. Sep 12 05:53:44.952890 systemd-logind[1441]: Session 9 logged out. Waiting for processes to exit. Sep 12 05:53:44.956217 systemd[1]: Started sshd@9-10.0.0.69:22-10.0.0.1:41872.service - OpenSSH per-connection server daemon (10.0.0.1:41872). Sep 12 05:53:44.956904 systemd-logind[1441]: Removed session 9. Sep 12 05:53:45.025869 sshd[2093]: Accepted publickey for core from 10.0.0.1 port 41872 ssh2: RSA SHA256:1ltQeNwsGZzWPatjm39NOSOhM7BVT7DhGn6/LONO9qE Sep 12 05:53:45.027397 sshd-session[2093]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Sep 12 05:53:45.032023 systemd-logind[1441]: New session 10 of user core. Sep 12 05:53:45.046763 systemd[1]: Started session-10.scope - Session 10 of User core. Sep 12 05:53:45.146144 sshd[2096]: Connection closed by 10.0.0.1 port 41872 Sep 12 05:53:45.146497 sshd-session[2093]: pam_unix(sshd:session): session closed for user core Sep 12 05:53:45.150795 systemd[1]: sshd@9-10.0.0.69:22-10.0.0.1:41872.service: Deactivated successfully. Sep 12 05:53:45.152888 systemd[1]: session-10.scope: Deactivated successfully. Sep 12 05:53:45.153646 systemd-logind[1441]: Session 10 logged out. Waiting for processes to exit. Sep 12 05:53:45.154986 systemd-logind[1441]: Removed session 10. Sep 12 05:54:10.991702 update_engine[1448]: I20250912 05:54:10.991500 1448 update_attempter.cc:509] Updating boot flags... Sep 12 05:54:37.505470 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:37.504911Z","caller":"traceutil/trace.go:171","msg":"trace[571009995] linearizableReadLoop","detail":"{readStateIndex:288; appliedIndex:287; }","duration":"129.982849ms","start":"2025-09-12T05:54:37.374902Z","end":"2025-09-12T05:54:37.504884Z","steps":["trace[571009995] 'read index received' (duration: 65.098741ms)","trace[571009995] 'applied index is now lower than readState.Index' (duration: 64.883577ms)"],"step_count":2} Sep 12 05:54:37.505470 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:37.504951Z","caller":"traceutil/trace.go:171","msg":"trace[1735642466] transaction","detail":"{read_only:false; response_revision:280; number_of_response:1; }","duration":"144.091662ms","start":"2025-09-12T05:54:37.360836Z","end":"2025-09-12T05:54:37.504928Z","steps":["trace[1735642466] 'process raft request' (duration: 79.203336ms)","trace[1735642466] 'compare' (duration: 64.768391ms)"],"step_count":2} Sep 12 05:54:37.505470 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:54:37.505136Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"130.178627ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io\" ","response":"range_response_count:0 size:5"} Sep 12 05:54:37.505470 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:37.505195Z","caller":"traceutil/trace.go:171","msg":"trace[1046639422] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io; range_end:; response_count:0; response_revision:280; }","duration":"130.307038ms","start":"2025-09-12T05:54:37.374870Z","end":"2025-09-12T05:54:37.505177Z","steps":["trace[1046639422] 'agreement among raft nodes before linearized reading' (duration: 130.168969ms)"],"step_count":1} Sep 12 05:54:37.647038 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:37.646608Z","caller":"traceutil/trace.go:171","msg":"trace[50853251] transaction","detail":"{read_only:false; response_revision:281; number_of_response:1; }","duration":"136.000268ms","start":"2025-09-12T05:54:37.510587Z","end":"2025-09-12T05:54:37.646587Z","steps":["trace[50853251] 'process raft request' (duration: 134.579437ms)"],"step_count":1} Sep 12 05:54:45.922272 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:45.921805Z","caller":"traceutil/trace.go:171","msg":"trace[1139327096] transaction","detail":"{read_only:false; response_revision:485; number_of_response:1; }","duration":"113.427601ms","start":"2025-09-12T05:54:45.808353Z","end":"2025-09-12T05:54:45.921781Z","steps":["trace[1139327096] 'process raft request' (duration: 113.233215ms)"],"step_count":1} Sep 12 05:54:45.995758 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:45.995220Z","caller":"traceutil/trace.go:171","msg":"trace[1372078943] linearizableReadLoop","detail":"{readStateIndex:500; appliedIndex:498; }","duration":"125.590581ms","start":"2025-09-12T05:54:45.869610Z","end":"2025-09-12T05:54:45.995201Z","steps":["trace[1372078943] 'read index received' (duration: 52.014104ms)","trace[1372078943] 'applied index is now lower than readState.Index' (duration: 73.575896ms)"],"step_count":2} Sep 12 05:54:45.995758 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:45.995266Z","caller":"traceutil/trace.go:171","msg":"trace[561052195] transaction","detail":"{read_only:false; response_revision:486; number_of_response:1; }","duration":"130.151106ms","start":"2025-09-12T05:54:45.865094Z","end":"2025-09-12T05:54:45.995245Z","steps":["trace[561052195] 'process raft request' (duration: 129.6849ms)"],"step_count":1} Sep 12 05:54:45.995758 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:54:45.995527Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"125.896545ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io\" ","response":"range_response_count:1 size:630504"} Sep 12 05:54:45.995988 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:54:45.995581Z","caller":"traceutil/trace.go:171","msg":"trace[1019021931] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io; range_end:; response_count:1; response_revision:486; }","duration":"125.980262ms","start":"2025-09-12T05:54:45.869593Z","end":"2025-09-12T05:54:45.995573Z","steps":["trace[1019021931] 'agreement among raft nodes before linearized reading' (duration: 125.678296ms)"],"step_count":1} Sep 12 05:55:02.117242 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.116437Z","caller":"traceutil/trace.go:171","msg":"trace[1110428970] transaction","detail":"{read_only:false; response_revision:800; number_of_response:1; }","duration":"114.04582ms","start":"2025-09-12T05:55:02.002372Z","end":"2025-09-12T05:55:02.116418Z","steps":["trace[1110428970] 'process raft request' (duration: 113.80318ms)"],"step_count":1} Sep 12 05:55:02.118245 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.116781Z","caller":"traceutil/trace.go:171","msg":"trace[630578658] transaction","detail":"{read_only:false; response_revision:801; number_of_response:1; }","duration":"114.327536ms","start":"2025-09-12T05:55:02.002385Z","end":"2025-09-12T05:55:02.116713Z","steps":["trace[630578658] 'process raft request' (duration: 114.006404ms)"],"step_count":1} Sep 12 05:55:02.118245 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.116956Z","caller":"traceutil/trace.go:171","msg":"trace[920043764] transaction","detail":"{read_only:false; response_revision:802; number_of_response:1; }","duration":"113.619023ms","start":"2025-09-12T05:55:02.003328Z","end":"2025-09-12T05:55:02.116947Z","steps":["trace[920043764] 'process raft request' (duration: 113.332188ms)"],"step_count":1} Sep 12 05:55:02.118245 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.116960Z","caller":"traceutil/trace.go:171","msg":"trace[240156364] transaction","detail":"{read_only:false; response_revision:804; number_of_response:1; }","duration":"111.729946ms","start":"2025-09-12T05:55:02.005218Z","end":"2025-09-12T05:55:02.116948Z","steps":["trace[240156364] 'process raft request' (duration: 111.57208ms)"],"step_count":1} Sep 12 05:55:02.118245 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.117014Z","caller":"traceutil/trace.go:171","msg":"trace[1289800122] transaction","detail":"{read_only:false; response_revision:803; number_of_response:1; }","duration":"111.99094ms","start":"2025-09-12T05:55:02.005016Z","end":"2025-09-12T05:55:02.117007Z","steps":["trace[1289800122] 'process raft request' (duration: 111.746287ms)"],"step_count":1} Sep 12 05:55:02.118245 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.117052Z","caller":"traceutil/trace.go:171","msg":"trace[735492373] transaction","detail":"{read_only:false; response_revision:805; number_of_response:1; }","duration":"111.34996ms","start":"2025-09-12T05:55:02.005696Z","end":"2025-09-12T05:55:02.117046Z","steps":["trace[735492373] 'process raft request' (duration: 111.118ms)"],"step_count":1} Sep 12 05:55:02.280710 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.280161Z","caller":"traceutil/trace.go:171","msg":"trace[1059713476] linearizableReadLoop","detail":"{readStateIndex:867; appliedIndex:866; }","duration":"107.611699ms","start":"2025-09-12T05:55:02.172521Z","end":"2025-09-12T05:55:02.280133Z","steps":["trace[1059713476] 'read index received' (duration: 51.514221ms)","trace[1059713476] 'applied index is now lower than readState.Index' (duration: 56.096957ms)"],"step_count":2} Sep 12 05:55:02.280710 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.280191Z","caller":"traceutil/trace.go:171","msg":"trace[1329280114] transaction","detail":"{read_only:false; response_revision:814; number_of_response:1; }","duration":"135.308492ms","start":"2025-09-12T05:55:02.144867Z","end":"2025-09-12T05:55:02.280176Z","steps":["trace[1329280114] 'process raft request' (duration: 79.192688ms)","trace[1329280114] 'compare' (duration: 55.965453ms)"],"step_count":2} Sep 12 05:55:02.280710 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:02.280327Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"107.780678ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/deployments/calico-system/calico-typha\" ","response":"range_response_count:1 size:6669"} Sep 12 05:55:02.280710 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:02.280380Z","caller":"traceutil/trace.go:171","msg":"trace[143303487] range","detail":"{range_begin:/registry/deployments/calico-system/calico-typha; range_end:; response_count:1; response_revision:814; }","duration":"107.883155ms","start":"2025-09-12T05:55:02.172481Z","end":"2025-09-12T05:55:02.280364Z","steps":["trace[143303487] 'agreement among raft nodes before linearized reading' (duration: 107.763945ms)"],"step_count":1} Sep 12 05:55:04.494062 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:04.493752Z","caller":"traceutil/trace.go:171","msg":"trace[352874285] transaction","detail":"{read_only:false; response_revision:835; number_of_response:1; }","duration":"152.708171ms","start":"2025-09-12T05:55:04.341027Z","end":"2025-09-12T05:55:04.493735Z","steps":["trace[352874285] 'process raft request' (duration: 152.490811ms)"],"step_count":1} Sep 12 05:55:04.675653 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:04.675389Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"102.755019ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/calico-kube-controllers\" ","response":"range_response_count:1 size:463"} Sep 12 05:55:04.675653 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:04.675446Z","caller":"traceutil/trace.go:171","msg":"trace[1352543559] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/calico-kube-controllers; range_end:; response_count:1; response_revision:835; }","duration":"102.825295ms","start":"2025-09-12T05:55:04.572607Z","end":"2025-09-12T05:55:04.675432Z","steps":["trace[1352543559] 'range keys from in-memory index tree' (duration: 102.687719ms)"],"step_count":1} Sep 12 05:55:09.937252 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:09.936890Z","caller":"traceutil/trace.go:171","msg":"trace[529453422] transaction","detail":"{read_only:false; response_revision:846; number_of_response:1; }","duration":"164.360839ms","start":"2025-09-12T05:55:09.772508Z","end":"2025-09-12T05:55:09.936869Z","steps":["trace[529453422] 'process raft request' (duration: 164.237472ms)"],"step_count":1} Sep 12 05:55:10.154402 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.153963Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"132.77681ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Sep 12 05:55:10.154673 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.154130Z","caller":"traceutil/trace.go:171","msg":"trace[250204660] transaction","detail":"{read_only:false; response_revision:847; number_of_response:1; }","duration":"381.599462ms","start":"2025-09-12T05:55:09.772508Z","end":"2025-09-12T05:55:10.154107Z","steps":["trace[250204660] 'process raft request' (duration: 248.184042ms)","trace[250204660] 'compare' (duration: 132.664284ms)"],"step_count":2} Sep 12 05:55:10.154673 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.154252Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:09.772492Z","time spent":"381.693744ms","remote":"10.0.0.78:57156","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":465,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Sep 12 05:55:10.154673 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.154296Z","caller":"traceutil/trace.go:171","msg":"trace[1408833383] linearizableReadLoop","detail":"{readStateIndex:901; appliedIndex:899; }","duration":"297.464552ms","start":"2025-09-12T05:55:09.856818Z","end":"2025-09-12T05:55:10.154283Z","steps":["trace[1408833383] 'read index received' (duration: 79.958465ms)","trace[1408833383] 'applied index is now lower than readState.Index' (duration: 217.504885ms)"],"step_count":2} Sep 12 05:55:10.266435 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.265842Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"111.7843ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:29"} Sep 12 05:55:10.266658 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.265906Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"409.062964ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:3643"} Sep 12 05:55:10.266658 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.265941Z","caller":"traceutil/trace.go:171","msg":"trace[1124280902] linearizableReadLoop","detail":"{readStateIndex:902; appliedIndex:901; }","duration":"111.607761ms","start":"2025-09-12T05:55:10.154319Z","end":"2025-09-12T05:55:10.265927Z","steps":["trace[1124280902] 'read index received' (duration: 160.259µs)","trace[1124280902] 'applied index is now lower than readState.Index' (duration: 111.44634ms)"],"step_count":2} Sep 12 05:55:10.266658 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.265969Z","caller":"traceutil/trace.go:171","msg":"trace[718399469] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:847; }","duration":"409.166935ms","start":"2025-09-12T05:55:09.856784Z","end":"2025-09-12T05:55:10.265951Z","steps":["trace[718399469] 'agreement among raft nodes before linearized reading' (duration: 297.53093ms)","trace[718399469] 'range keys from in-memory index tree' (duration: 111.467571ms)"],"step_count":2} Sep 12 05:55:10.266658 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.266010Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:09.856766Z","time spent":"409.235797ms","remote":"10.0.0.78:41224","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":1,"response size":3667,"request content":"key:\"/registry/operator.tigera.io/installations/default\" "} Sep 12 05:55:10.266820 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.266087Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"298.099015ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/apiservers/default\" ","response":"range_response_count:1 size:1504"} Sep 12 05:55:10.266820 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.266112Z","caller":"traceutil/trace.go:171","msg":"trace[755619832] range","detail":"{range_begin:/registry/operator.tigera.io/apiservers/default; range_end:; response_count:1; response_revision:847; }","duration":"298.157345ms","start":"2025-09-12T05:55:09.967946Z","end":"2025-09-12T05:55:10.266103Z","steps":["trace[755619832] 'agreement among raft nodes before linearized reading' (duration: 298.051562ms)"],"step_count":1} Sep 12 05:55:10.266820 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:10.266187Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"122.819758ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/whiskers/default\" ","response":"range_response_count:1 size:948"} Sep 12 05:55:10.266820 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:10.266218Z","caller":"traceutil/trace.go:171","msg":"trace[2011841205] range","detail":"{range_begin:/registry/operator.tigera.io/whiskers/default; range_end:; response_count:1; response_revision:847; }","duration":"122.878702ms","start":"2025-09-12T05:55:10.143331Z","end":"2025-09-12T05:55:10.266210Z","steps":["trace[2011841205] 'agreement among raft nodes before linearized reading' (duration: 122.643228ms)"],"step_count":1} Sep 12 05:55:13.234720 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:13.234327Z","caller":"traceutil/trace.go:171","msg":"trace[951722690] transaction","detail":"{read_only:false; response_revision:851; number_of_response:1; }","duration":"137.842836ms","start":"2025-09-12T05:55:13.096467Z","end":"2025-09-12T05:55:13.234310Z","steps":["trace[951722690] 'process raft request' (duration: 137.75067ms)"],"step_count":1} Sep 12 05:55:14.106599 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.104632Z","caller":"traceutil/trace.go:171","msg":"trace[1338605656] transaction","detail":"{read_only:false; response_revision:879; number_of_response:1; }","duration":"145.895427ms","start":"2025-09-12T05:55:13.958711Z","end":"2025-09-12T05:55:14.104607Z","steps":["trace[1338605656] 'process raft request' (duration: 106.476639ms)","trace[1338605656] 'compare' (duration: 38.975318ms)"],"step_count":2} Sep 12 05:55:14.285983 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.285563Z","caller":"traceutil/trace.go:171","msg":"trace[1063604580] linearizableReadLoop","detail":"{readStateIndex:939; appliedIndex:938; }","duration":"104.210009ms","start":"2025-09-12T05:55:14.181307Z","end":"2025-09-12T05:55:14.285517Z","steps":["trace[1063604580] 'read index received' (duration: 39.69652ms)","trace[1063604580] 'applied index is now lower than readState.Index' (duration: 64.511595ms)"],"step_count":2} Sep 12 05:55:14.285983 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.285595Z","caller":"traceutil/trace.go:171","msg":"trace[1375769371] transaction","detail":"{read_only:false; response_revision:881; number_of_response:1; }","duration":"123.018974ms","start":"2025-09-12T05:55:14.162561Z","end":"2025-09-12T05:55:14.285580Z","steps":["trace[1375769371] 'process raft request' (duration: 58.446662ms)","trace[1375769371] 'compare' (duration: 64.413407ms)"],"step_count":2} Sep 12 05:55:14.286609 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:14.285743Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"104.421895ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:3643"} Sep 12 05:55:14.286609 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.285768Z","caller":"traceutil/trace.go:171","msg":"trace[1602120272] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:881; }","duration":"104.47088ms","start":"2025-09-12T05:55:14.181290Z","end":"2025-09-12T05:55:14.285761Z","steps":["trace[1602120272] 'agreement among raft nodes before linearized reading' (duration: 104.369134ms)"],"step_count":1} Sep 12 05:55:14.878069 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.877696Z","caller":"traceutil/trace.go:171","msg":"trace[1842473167] transaction","detail":"{read_only:false; response_revision:882; number_of_response:1; }","duration":"101.812467ms","start":"2025-09-12T05:55:14.775867Z","end":"2025-09-12T05:55:14.877680Z","steps":["trace[1842473167] 'process raft request' (duration: 101.707616ms)"],"step_count":1} Sep 12 05:55:14.968115 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:14.967633Z","caller":"traceutil/trace.go:171","msg":"trace[1245724853] transaction","detail":"{read_only:false; response_revision:883; number_of_response:1; }","duration":"189.330044ms","start":"2025-09-12T05:55:14.778270Z","end":"2025-09-12T05:55:14.967600Z","steps":["trace[1245724853] 'process raft request' (duration: 189.141862ms)"],"step_count":1} Sep 12 05:55:15.101067 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:15.100688Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"114.835198ms","expected-duration":"100ms","prefix":"","request":"header: lease_grant:","response":"size:41"} Sep 12 05:55:15.101210 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:15.100868Z","caller":"traceutil/trace.go:171","msg":"trace[1459450710] linearizableReadLoop","detail":"{readStateIndex:942; appliedIndex:941; }","duration":"127.092848ms","start":"2025-09-12T05:55:14.973750Z","end":"2025-09-12T05:55:15.100843Z","steps":["trace[1459450710] 'read index received' (duration: 12.037297ms)","trace[1459450710] 'applied index is now lower than readState.Index' (duration: 115.053708ms)"],"step_count":2} Sep 12 05:55:15.101427 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:15.101126Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"127.368166ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/calico-system/whisker-7c56fb5448-5dkvd\" ","response":"range_response_count:1 size:6255"} Sep 12 05:55:15.101427 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:15.101251Z","caller":"traceutil/trace.go:171","msg":"trace[312263593] range","detail":"{range_begin:/registry/pods/calico-system/whisker-7c56fb5448-5dkvd; range_end:; response_count:1; response_revision:884; }","duration":"127.538552ms","start":"2025-09-12T05:55:14.973698Z","end":"2025-09-12T05:55:15.101236Z","steps":["trace[312263593] 'agreement among raft nodes before linearized reading' (duration: 127.27103ms)"],"step_count":1} Sep 12 05:55:16.027599 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.027245Z","caller":"traceutil/trace.go:171","msg":"trace[1485980527] transaction","detail":"{read_only:false; response_revision:915; number_of_response:1; }","duration":"149.472921ms","start":"2025-09-12T05:55:15.877757Z","end":"2025-09-12T05:55:16.027230Z","steps":["trace[1485980527] 'process raft request' (duration: 149.370594ms)"],"step_count":1} Sep 12 05:55:16.214583 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.214251Z","caller":"traceutil/trace.go:171","msg":"trace[128768225] transaction","detail":"{read_only:false; response_revision:918; number_of_response:1; }","duration":"152.400938ms","start":"2025-09-12T05:55:16.061828Z","end":"2025-09-12T05:55:16.214229Z","steps":["trace[128768225] 'process raft request' (duration: 70.384658ms)","trace[128768225] 'compare' (duration: 81.926577ms)"],"step_count":2} Sep 12 05:55:16.401989 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.401631Z","caller":"traceutil/trace.go:171","msg":"trace[1587080510] linearizableReadLoop","detail":"{readStateIndex:978; appliedIndex:977; }","duration":"178.757251ms","start":"2025-09-12T05:55:16.222857Z","end":"2025-09-12T05:55:16.401614Z","steps":["trace[1587080510] 'read index received' (duration: 178.263313ms)","trace[1587080510] 'applied index is now lower than readState.Index' (duration: 493.176µs)"],"step_count":2} Sep 12 05:55:16.401989 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.401653Z","caller":"traceutil/trace.go:171","msg":"trace[2075551108] transaction","detail":"{read_only:false; response_revision:919; number_of_response:1; }","duration":"181.541338ms","start":"2025-09-12T05:55:16.220099Z","end":"2025-09-12T05:55:16.401640Z","steps":["trace[2075551108] 'process raft request' (duration: 180.954382ms)"],"step_count":1} Sep 12 05:55:16.401989 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:16.401795Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"178.923489ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/clusterinformations/default\" ","response":"range_response_count:1 size:886"} Sep 12 05:55:16.401989 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.401819Z","caller":"traceutil/trace.go:171","msg":"trace[41401967] range","detail":"{range_begin:/registry/crd.projectcalico.org/clusterinformations/default; range_end:; response_count:1; response_revision:919; }","duration":"178.970779ms","start":"2025-09-12T05:55:16.222843Z","end":"2025-09-12T05:55:16.401814Z","steps":["trace[41401967] 'agreement among raft nodes before linearized reading' (duration: 178.845049ms)"],"step_count":1} Sep 12 05:55:16.450343 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.449820Z","caller":"traceutil/trace.go:171","msg":"trace[673440477] transaction","detail":"{read_only:false; response_revision:920; number_of_response:1; }","duration":"223.945109ms","start":"2025-09-12T05:55:16.225856Z","end":"2025-09-12T05:55:16.449801Z","steps":["trace[673440477] 'process raft request' (duration: 223.828064ms)"],"step_count":1} Sep 12 05:55:16.450343 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:16.449922Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"215.933608ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/bgpconfigurations/default\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:16.450343 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.449957Z","caller":"traceutil/trace.go:171","msg":"trace[1988448709] range","detail":"{range_begin:/registry/crd.projectcalico.org/bgpconfigurations/default; range_end:; response_count:0; response_revision:921; }","duration":"215.979747ms","start":"2025-09-12T05:55:16.233970Z","end":"2025-09-12T05:55:16.449949Z","steps":["trace[1988448709] 'agreement among raft nodes before linearized reading' (duration: 215.903621ms)"],"step_count":1} Sep 12 05:55:16.450343 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:16.449954Z","caller":"traceutil/trace.go:171","msg":"trace[1749346358] transaction","detail":"{read_only:false; response_revision:921; number_of_response:1; }","duration":"160.550923ms","start":"2025-09-12T05:55:16.289393Z","end":"2025-09-12T05:55:16.449944Z","steps":["trace[1749346358] 'process raft request' (duration: 160.372621ms)"],"step_count":1} Sep 12 05:55:18.412460 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:18.412085Z","caller":"traceutil/trace.go:171","msg":"trace[335457756] transaction","detail":"{read_only:false; response_revision:988; number_of_response:1; }","duration":"145.720216ms","start":"2025-09-12T05:55:18.266347Z","end":"2025-09-12T05:55:18.412067Z","steps":["trace[335457756] 'process raft request' (duration: 145.456441ms)"],"step_count":1} Sep 12 05:55:18.676746 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:18.676262Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"103.422877ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:18.676746 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:18.676314Z","caller":"traceutil/trace.go:171","msg":"trace[1186830235] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:989; }","duration":"103.505887ms","start":"2025-09-12T05:55:18.572795Z","end":"2025-09-12T05:55:18.676301Z","steps":["trace[1186830235] 'range keys from in-memory index tree' (duration: 103.375316ms)"],"step_count":1} Sep 12 05:55:26.034461 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:26.034044Z","caller":"traceutil/trace.go:171","msg":"trace[336437605] transaction","detail":"{read_only:false; response_revision:1045; number_of_response:1; }","duration":"198.585644ms","start":"2025-09-12T05:55:25.835438Z","end":"2025-09-12T05:55:26.034024Z","steps":["trace[336437605] 'process raft request' (duration: 198.465905ms)"],"step_count":1} Sep 12 05:55:28.068712 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:28.068372Z","caller":"traceutil/trace.go:171","msg":"trace[653513305] transaction","detail":"{read_only:false; response_revision:1056; number_of_response:1; }","duration":"103.006569ms","start":"2025-09-12T05:55:27.965345Z","end":"2025-09-12T05:55:28.068352Z","steps":["trace[653513305] 'process raft request' (duration: 102.895807ms)"],"step_count":1} Sep 12 05:55:30.565644 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:30.565231Z","caller":"traceutil/trace.go:171","msg":"trace[759099918] transaction","detail":"{read_only:false; number_of_response:0; response_revision:1085; }","duration":"252.648626ms","start":"2025-09-12T05:55:30.312564Z","end":"2025-09-12T05:55:30.565213Z","steps":["trace[759099918] 'process raft request' (duration: 164.541928ms)","trace[759099918] 'compare' (duration: 88.06551ms)"],"step_count":2} Sep 12 05:55:31.021114 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:31.020748Z","caller":"traceutil/trace.go:171","msg":"trace[912453462] transaction","detail":"{read_only:false; response_revision:1089; number_of_response:1; }","duration":"202.536316ms","start":"2025-09-12T05:55:30.818196Z","end":"2025-09-12T05:55:31.020732Z","steps":["trace[912453462] 'process raft request' (duration: 202.045742ms)"],"step_count":1} Sep 12 05:55:31.021114 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:31.020832Z","caller":"traceutil/trace.go:171","msg":"trace[792538312] transaction","detail":"{read_only:false; response_revision:1090; number_of_response:1; }","duration":"202.24954ms","start":"2025-09-12T05:55:30.818578Z","end":"2025-09-12T05:55:31.020827Z","steps":["trace[792538312] 'process raft request' (duration: 202.126946ms)"],"step_count":1} Sep 12 05:55:31.035300 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:31.034766Z","caller":"traceutil/trace.go:171","msg":"trace[93416769] transaction","detail":"{read_only:false; response_revision:1091; number_of_response:1; }","duration":"214.611638ms","start":"2025-09-12T05:55:30.820130Z","end":"2025-09-12T05:55:31.034741Z","steps":["trace[93416769] 'process raft request' (duration: 214.491309ms)"],"step_count":1} Sep 12 05:55:31.035300 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:31.034863Z","caller":"traceutil/trace.go:171","msg":"trace[818548510] transaction","detail":"{read_only:false; response_revision:1093; number_of_response:1; }","duration":"211.21618ms","start":"2025-09-12T05:55:30.823642Z","end":"2025-09-12T05:55:31.034858Z","steps":["trace[818548510] 'process raft request' (duration: 211.081874ms)"],"step_count":1} Sep 12 05:55:31.035300 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:31.034894Z","caller":"traceutil/trace.go:171","msg":"trace[1187280744] transaction","detail":"{read_only:false; response_revision:1092; number_of_response:1; }","duration":"212.482652ms","start":"2025-09-12T05:55:30.822404Z","end":"2025-09-12T05:55:31.034886Z","steps":["trace[1187280744] 'process raft request' (duration: 212.293532ms)"],"step_count":1} Sep 12 05:55:34.356883 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:34.356465Z","caller":"traceutil/trace.go:171","msg":"trace[1177959922] linearizableReadLoop","detail":"{readStateIndex:1330; appliedIndex:1329; }","duration":"310.468927ms","start":"2025-09-12T05:55:34.045978Z","end":"2025-09-12T05:55:34.356447Z","steps":["trace[1177959922] 'read index received' (duration: 310.052636ms)","trace[1177959922] 'applied index is now lower than readState.Index' (duration: 415.75µs)"],"step_count":2} Sep 12 05:55:34.356883 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:34.356504Z","caller":"traceutil/trace.go:171","msg":"trace[486836610] transaction","detail":"{read_only:false; response_revision:1129; number_of_response:1; }","duration":"313.032794ms","start":"2025-09-12T05:55:34.043454Z","end":"2025-09-12T05:55:34.356487Z","steps":["trace[486836610] 'process raft request' (duration: 312.582718ms)"],"step_count":1} Sep 12 05:55:34.357699 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:34.356574Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"310.578205ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true ","response":"range_response_count:0 size:5"} Sep 12 05:55:34.357699 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:34.356595Z","caller":"traceutil/trace.go:171","msg":"trace[2082408640] range","detail":"{range_begin:/registry/statefulsets/; range_end:/registry/statefulsets0; response_count:0; response_revision:1129; }","duration":"310.630284ms","start":"2025-09-12T05:55:34.045959Z","end":"2025-09-12T05:55:34.356589Z","steps":["trace[2082408640] 'agreement among raft nodes before linearized reading' (duration: 310.566091ms)"],"step_count":1} Sep 12 05:55:34.357699 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:34.356613Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:34.045948Z","time spent":"310.658278ms","remote":"10.0.0.78:57382","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":0,"response size":29,"request content":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true "} Sep 12 05:55:34.357699 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:34.356619Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:34.043430Z","time spent":"313.13559ms","remote":"10.0.0.78:41228","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1489,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Sep 12 05:55:39.148187 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:39.147724Z","caller":"traceutil/trace.go:171","msg":"trace[2112753468] linearizableReadLoop","detail":"{readStateIndex:1389; appliedIndex:1388; }","duration":"102.294244ms","start":"2025-09-12T05:55:39.045406Z","end":"2025-09-12T05:55:39.147700Z","steps":["trace[2112753468] 'read index received' (duration: 84.211731ms)","trace[2112753468] 'applied index is now lower than readState.Index' (duration: 18.081851ms)"],"step_count":2} Sep 12 05:55:39.148187 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:39.147756Z","caller":"traceutil/trace.go:171","msg":"trace[725097837] transaction","detail":"{read_only:false; response_revision:1180; number_of_response:1; }","duration":"127.559728ms","start":"2025-09-12T05:55:39.020181Z","end":"2025-09-12T05:55:39.147740Z","steps":["trace[725097837] 'process raft request' (duration: 109.464521ms)","trace[725097837] 'compare' (duration: 17.973227ms)"],"step_count":2} Sep 12 05:55:39.148187 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:39.147849Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"102.435352ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/tigerastatuses/goldmane\" ","response":"range_response_count:1 size:1208"} Sep 12 05:55:39.148187 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:39.147871Z","caller":"traceutil/trace.go:171","msg":"trace[1193623771] range","detail":"{range_begin:/registry/operator.tigera.io/tigerastatuses/goldmane; range_end:; response_count:1; response_revision:1180; }","duration":"102.502108ms","start":"2025-09-12T05:55:39.045362Z","end":"2025-09-12T05:55:39.147864Z","steps":["trace[1193623771] 'agreement among raft nodes before linearized reading' (duration: 102.411115ms)"],"step_count":1} Sep 12 05:55:49.071848 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.071264Z","caller":"traceutil/trace.go:171","msg":"trace[1291364535] linearizableReadLoop","detail":"{readStateIndex:1438; appliedIndex:1436; }","duration":"180.823309ms","start":"2025-09-12T05:55:48.890421Z","end":"2025-09-12T05:55:49.071245Z","steps":["trace[1291364535] 'read index received' (duration: 9.203021ms)","trace[1291364535] 'applied index is now lower than readState.Index' (duration: 171.618104ms)"],"step_count":2} Sep 12 05:55:49.071848 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.071341Z","caller":"traceutil/trace.go:171","msg":"trace[874757011] transaction","detail":"{read_only:false; response_revision:1224; number_of_response:1; }","duration":"186.085782ms","start":"2025-09-12T05:55:48.885214Z","end":"2025-09-12T05:55:49.071300Z","steps":["trace[874757011] 'process raft request' (duration: 162.633877ms)","trace[874757011] 'compare' (duration: 23.299066ms)"],"step_count":2} Sep 12 05:55:49.071848 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:49.071499Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"181.062493ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:3643"} Sep 12 05:55:49.071848 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.071557Z","caller":"traceutil/trace.go:171","msg":"trace[852235626] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:1224; }","duration":"181.120083ms","start":"2025-09-12T05:55:48.890403Z","end":"2025-09-12T05:55:49.071523Z","steps":["trace[852235626] 'agreement among raft nodes before linearized reading' (duration: 180.913521ms)"],"step_count":1} Sep 12 05:55:49.101151 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.100775Z","caller":"traceutil/trace.go:171","msg":"trace[331987428] transaction","detail":"{read_only:false; response_revision:1225; number_of_response:1; }","duration":"148.88355ms","start":"2025-09-12T05:55:48.951868Z","end":"2025-09-12T05:55:49.100752Z","steps":["trace[331987428] 'process raft request' (duration: 148.762531ms)"],"step_count":1} Sep 12 05:55:49.240478 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.239936Z","caller":"traceutil/trace.go:171","msg":"trace[241803969] linearizableReadLoop","detail":"{readStateIndex:1441; appliedIndex:1440; }","duration":"100.904594ms","start":"2025-09-12T05:55:49.139012Z","end":"2025-09-12T05:55:49.239917Z","steps":["trace[241803969] 'read index received' (duration: 59.283223ms)","trace[241803969] 'applied index is now lower than readState.Index' (duration: 41.62073ms)"],"step_count":2} Sep 12 05:55:49.240478 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.240038Z","caller":"traceutil/trace.go:171","msg":"trace[825058987] transaction","detail":"{read_only:false; response_revision:1227; number_of_response:1; }","duration":"113.795439ms","start":"2025-09-12T05:55:49.126230Z","end":"2025-09-12T05:55:49.240025Z","steps":["trace[825058987] 'process raft request' (duration: 72.162917ms)","trace[825058987] 'compare' (duration: 41.422304ms)"],"step_count":2} Sep 12 05:55:49.240478 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:49.240141Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"101.116876ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/networkpolicies.crd.projectcalico.org\" ","response":"range_response_count:1 size:34255"} Sep 12 05:55:49.240478 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.240176Z","caller":"traceutil/trace.go:171","msg":"trace[718912143] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/networkpolicies.crd.projectcalico.org; range_end:; response_count:1; response_revision:1227; }","duration":"101.164185ms","start":"2025-09-12T05:55:49.139003Z","end":"2025-09-12T05:55:49.240168Z","steps":["trace[718912143] 'agreement among raft nodes before linearized reading' (duration: 100.989274ms)"],"step_count":1} Sep 12 05:55:49.499875 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:49.498997Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"145.867285ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/bgpfilters.crd.projectcalico.org\" ","response":"range_response_count:1 size:5583"} Sep 12 05:55:49.499875 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.499081Z","caller":"traceutil/trace.go:171","msg":"trace[710915707] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/bgpfilters.crd.projectcalico.org; range_end:; response_count:1; response_revision:1227; }","duration":"145.993002ms","start":"2025-09-12T05:55:49.353070Z","end":"2025-09-12T05:55:49.499063Z","steps":["trace[710915707] 'range keys from in-memory index tree' (duration: 145.781863ms)"],"step_count":1} Sep 12 05:55:49.791851 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:49.791361Z","caller":"traceutil/trace.go:171","msg":"trace[452480581] transaction","detail":"{read_only:false; response_revision:1228; number_of_response:1; }","duration":"101.877699ms","start":"2025-09-12T05:55:49.689461Z","end":"2025-09-12T05:55:49.791339Z","steps":["trace[452480581] 'process raft request' (duration: 101.729839ms)"],"step_count":1} Sep 12 05:55:50.354700 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:50.354216Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"127.384307ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:29"} Sep 12 05:55:50.354700 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:50.354301Z","caller":"traceutil/trace.go:171","msg":"trace[1215709283] linearizableReadLoop","detail":"{readStateIndex:1443; appliedIndex:1442; }","duration":"116.626568ms","start":"2025-09-12T05:55:50.237660Z","end":"2025-09-12T05:55:50.354286Z","steps":["trace[1215709283] 'read index received' (duration: 21.37µs)","trace[1215709283] 'applied index is now lower than readState.Index' (duration: 116.603946ms)"],"step_count":2} Sep 12 05:55:50.355465 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:50.354505Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.82292ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:3643"} Sep 12 05:55:50.355465 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:50.354568Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"109.700408ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io\" ","response":"range_response_count:1 size:630504"} Sep 12 05:55:50.355465 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:50.354582Z","caller":"traceutil/trace.go:171","msg":"trace[1547091188] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:1228; }","duration":"116.950112ms","start":"2025-09-12T05:55:50.237623Z","end":"2025-09-12T05:55:50.354573Z","steps":["trace[1547091188] 'agreement among raft nodes before linearized reading' (duration: 116.720747ms)"],"step_count":1} Sep 12 05:55:50.355465 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:50.354602Z","caller":"traceutil/trace.go:171","msg":"trace[41444976] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/installations.operator.tigera.io; range_end:; response_count:1; response_revision:1228; }","duration":"109.749822ms","start":"2025-09-12T05:55:50.244846Z","end":"2025-09-12T05:55:50.354595Z","steps":["trace[41444976] 'agreement among raft nodes before linearized reading' (duration: 109.514717ms)"],"step_count":1} Sep 12 05:55:51.005556 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.005153Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"141.807507ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-kube-controllers\" ","response":"range_response_count:1 size:656"} Sep 12 05:55:51.005556 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.005226Z","caller":"traceutil/trace.go:171","msg":"trace[1877906793] range","detail":"{range_begin:/registry/clusterrolebindings/calico-kube-controllers; range_end:; response_count:1; response_revision:1230; }","duration":"141.89908ms","start":"2025-09-12T05:55:50.863310Z","end":"2025-09-12T05:55:51.005209Z","steps":["trace[1877906793] 'range keys from in-memory index tree' (duration: 141.680848ms)"],"step_count":1} Sep 12 05:55:51.159639 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.159154Z","caller":"traceutil/trace.go:171","msg":"trace[1008991066] linearizableReadLoop","detail":"{readStateIndex:1446; appliedIndex:1445; }","duration":"124.162026ms","start":"2025-09-12T05:55:51.034976Z","end":"2025-09-12T05:55:51.159138Z","steps":["trace[1008991066] 'read index received' (duration: 123.975974ms)","trace[1008991066] 'applied index is now lower than readState.Index' (duration: 185.481µs)"],"step_count":2} Sep 12 05:55:51.159639 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.159204Z","caller":"traceutil/trace.go:171","msg":"trace[351341584] transaction","detail":"{read_only:false; response_revision:1231; number_of_response:1; }","duration":"139.999291ms","start":"2025-09-12T05:55:51.019186Z","end":"2025-09-12T05:55:51.159185Z","steps":["trace[351341584] 'process raft request' (duration: 139.851813ms)"],"step_count":1} Sep 12 05:55:51.159639 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.159259Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"124.249903ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:5444"} Sep 12 05:55:51.159639 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.159310Z","caller":"traceutil/trace.go:171","msg":"trace[217273649] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:1231; }","duration":"124.373087ms","start":"2025-09-12T05:55:51.034930Z","end":"2025-09-12T05:55:51.159303Z","steps":["trace[217273649] 'agreement among raft nodes before linearized reading' (duration: 124.261175ms)"],"step_count":1} Sep 12 05:55:51.607635 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.606991Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"194.358288ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:51.607635 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607050Z","caller":"traceutil/trace.go:171","msg":"trace[873061686] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1231; }","duration":"194.440544ms","start":"2025-09-12T05:55:51.412599Z","end":"2025-09-12T05:55:51.607040Z","steps":["trace[873061686] 'range keys from in-memory index tree' (duration: 194.279358ms)"],"step_count":1} Sep 12 05:55:51.607635 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607096Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"385.116394ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/calico-crds\" ","response":"range_response_count:1 size:1255"} Sep 12 05:55:51.607635 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607110Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"338.759447ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/volumeattachments/\" range_end:\"/registry/volumeattachments0\" count_only:true ","response":"range_response_count:0 size:5"} Sep 12 05:55:51.607635 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607118Z","caller":"traceutil/trace.go:171","msg":"trace[2109074718] range","detail":"{range_begin:/registry/clusterroles/calico-crds; range_end:; response_count:1; response_revision:1231; }","duration":"385.147923ms","start":"2025-09-12T05:55:51.221964Z","end":"2025-09-12T05:55:51.607112Z","steps":["trace[2109074718] 'range keys from in-memory index tree' (duration: 385.026184ms)"],"step_count":1} Sep 12 05:55:51.608178 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607130Z","caller":"traceutil/trace.go:171","msg":"trace[102030706] range","detail":"{range_begin:/registry/volumeattachments/; range_end:/registry/volumeattachments0; response_count:0; response_revision:1231; }","duration":"338.785095ms","start":"2025-09-12T05:55:51.268333Z","end":"2025-09-12T05:55:51.607118Z","steps":["trace[102030706] 'count revisions from in-memory index tree' (duration: 338.710104ms)"],"step_count":1} Sep 12 05:55:51.608178 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607136Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.221956Z","time spent":"385.174003ms","remote":"10.0.0.78:57226","response type":"/etcdserverpb.KV/Range","request count":0,"request size":36,"response count":1,"response size":1279,"request content":"key:\"/registry/clusterroles/calico-crds\" "} Sep 12 05:55:51.608178 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607146Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.268324Z","time spent":"338.814522ms","remote":"10.0.0.78:57282","response type":"/etcdserverpb.KV/Range","request count":0,"request size":62,"response count":0,"response size":29,"request content":"key:\"/registry/volumeattachments/\" range_end:\"/registry/volumeattachments0\" count_only:true "} Sep 12 05:55:51.608178 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607014Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"381.054671ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:5444"} Sep 12 05:55:51.608281 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607187Z","caller":"traceutil/trace.go:171","msg":"trace[12579274] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:1231; }","duration":"381.239301ms","start":"2025-09-12T05:55:51.225945Z","end":"2025-09-12T05:55:51.607184Z","steps":["trace[12579274] 'range keys from in-memory index tree' (duration: 381.016158ms)"],"step_count":1} Sep 12 05:55:51.608281 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607200Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.225940Z","time spent":"381.255923ms","remote":"10.0.0.78:41224","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":1,"response size":5468,"request content":"key:\"/registry/operator.tigera.io/installations/default\" "} Sep 12 05:55:51.608281 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607118Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"356.254512ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/jobs/\" range_end:\"/registry/jobs0\" count_only:true ","response":"range_response_count:0 size:5"} Sep 12 05:55:51.608281 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607235Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"384.320195ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/whiskers/default\" ","response":"range_response_count:1 size:948"} Sep 12 05:55:51.608281 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607249Z","caller":"traceutil/trace.go:171","msg":"trace[44925007] range","detail":"{range_begin:/registry/operator.tigera.io/whiskers/default; range_end:; response_count:1; response_revision:1231; }","duration":"384.340945ms","start":"2025-09-12T05:55:51.222903Z","end":"2025-09-12T05:55:51.607244Z","steps":["trace[44925007] 'range keys from in-memory index tree' (duration: 384.277446ms)"],"step_count":1} Sep 12 05:55:51.608402 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607262Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.222897Z","time spent":"384.361083ms","remote":"10.0.0.78:41250","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":972,"request content":"key:\"/registry/operator.tigera.io/whiskers/default\" "} Sep 12 05:55:51.608402 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607203Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"384.916787ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/tigera-csr-creator\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:51.608402 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607275Z","caller":"traceutil/trace.go:171","msg":"trace[1829211716] range","detail":"{range_begin:/registry/clusterroles/tigera-csr-creator; range_end:; response_count:0; response_revision:1231; }","duration":"384.998481ms","start":"2025-09-12T05:55:51.222273Z","end":"2025-09-12T05:55:51.607272Z","steps":["trace[1829211716] 'range keys from in-memory index tree' (duration: 384.883363ms)"],"step_count":1} Sep 12 05:55:51.608402 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607288Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.222267Z","time spent":"385.016034ms","remote":"10.0.0.78:57226","response type":"/etcdserverpb.KV/Range","request count":0,"request size":43,"response count":0,"response size":29,"request content":"key:\"/registry/clusterroles/tigera-csr-creator\" "} Sep 12 05:55:51.608402 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607248Z","caller":"traceutil/trace.go:171","msg":"trace[2080181769] range","detail":"{range_begin:/registry/jobs/; range_end:/registry/jobs0; response_count:0; response_revision:1231; }","duration":"356.452907ms","start":"2025-09-12T05:55:51.250790Z","end":"2025-09-12T05:55:51.607243Z","steps":["trace[2080181769] 'count revisions from in-memory index tree' (duration: 356.185712ms)"],"step_count":1} Sep 12 05:55:51.608523 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607312Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.250773Z","time spent":"356.533821ms","remote":"10.0.0.78:57116","response type":"/etcdserverpb.KV/Range","request count":0,"request size":36,"response count":0,"response size":29,"request content":"key:\"/registry/jobs/\" range_end:\"/registry/jobs0\" count_only:true "} Sep 12 05:55:51.608523 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607319Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"370.106377ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/felixconfigurations.crd.projectcalico.org\" ","response":"range_response_count:1 size:55540"} Sep 12 05:55:51.608523 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:51.607378Z","caller":"traceutil/trace.go:171","msg":"trace[1783190752] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/felixconfigurations.crd.projectcalico.org; range_end:; response_count:1; response_revision:1231; }","duration":"370.156902ms","start":"2025-09-12T05:55:51.237196Z","end":"2025-09-12T05:55:51.607353Z","steps":["trace[1783190752] 'range keys from in-memory index tree' (duration: 369.947655ms)"],"step_count":1} Sep 12 05:55:51.608523 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:51.607419Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:51.237191Z","time spent":"370.214571ms","remote":"10.0.0.78:56902","response type":"/etcdserverpb.KV/Range","request count":0,"request size":100,"response count":1,"response size":55564,"request content":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/felixconfigurations.crd.projectcalico.org\" "} Sep 12 05:55:52.032419 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:52.031901Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.493878ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/bgpconfigurations.crd.projectcalico.org\" ","response":"range_response_count:1 size:8602"} Sep 12 05:55:52.032419 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:52.031940Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"120.19815ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-tiered-policy-passthrough\" ","response":"range_response_count:1 size:680"} Sep 12 05:55:52.032419 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:52.031971Z","caller":"traceutil/trace.go:171","msg":"trace[1686479889] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/bgpconfigurations.crd.projectcalico.org; range_end:; response_count:1; response_revision:1232; }","duration":"117.604587ms","start":"2025-09-12T05:55:51.914345Z","end":"2025-09-12T05:55:52.031950Z","steps":["trace[1686479889] 'range keys from in-memory index tree' (duration: 117.35225ms)"],"step_count":1} Sep 12 05:55:52.032717 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:52.032013Z","caller":"traceutil/trace.go:171","msg":"trace[1704541481] range","detail":"{range_begin:/registry/clusterrolebindings/calico-tiered-policy-passthrough; range_end:; response_count:1; response_revision:1232; }","duration":"120.306615ms","start":"2025-09-12T05:55:51.911676Z","end":"2025-09-12T05:55:52.031983Z","steps":["trace[1704541481] 'range keys from in-memory index tree' (duration: 120.052673ms)"],"step_count":1} Sep 12 05:55:53.763280 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:53.762860Z","caller":"traceutil/trace.go:171","msg":"trace[493060048] linearizableReadLoop","detail":"{readStateIndex:1451; appliedIndex:1450; }","duration":"101.481859ms","start":"2025-09-12T05:55:53.661361Z","end":"2025-09-12T05:55:53.762843Z","steps":["trace[493060048] 'read index received' (duration: 101.337837ms)","trace[493060048] 'applied index is now lower than readState.Index' (duration: 143.602µs)"],"step_count":2} Sep 12 05:55:53.763280 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:53.762929Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"101.554216ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/tigera-uisettingsgroup-getter\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:53.763280 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:53.762911Z","caller":"traceutil/trace.go:171","msg":"trace[1311923754] transaction","detail":"{read_only:false; response_revision:1236; number_of_response:1; }","duration":"135.383083ms","start":"2025-09-12T05:55:53.627502Z","end":"2025-09-12T05:55:53.762885Z","steps":["trace[1311923754] 'process raft request' (duration: 135.25993ms)"],"step_count":1} Sep 12 05:55:53.763280 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:53.762946Z","caller":"traceutil/trace.go:171","msg":"trace[1540504478] range","detail":"{range_begin:/registry/clusterrolebindings/tigera-uisettingsgroup-getter; range_end:; response_count:0; response_revision:1236; }","duration":"101.594724ms","start":"2025-09-12T05:55:53.661346Z","end":"2025-09-12T05:55:53.762940Z","steps":["trace[1540504478] 'agreement among raft nodes before linearized reading' (duration: 101.557774ms)"],"step_count":1} Sep 12 05:55:54.431169 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430393Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"475.449217ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Sep 12 05:55:54.431169 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430502Z","caller":"traceutil/trace.go:171","msg":"trace[118181634] linearizableReadLoop","detail":"{readStateIndex:1452; appliedIndex:1451; }","duration":"596.465281ms","start":"2025-09-12T05:55:53.834022Z","end":"2025-09-12T05:55:54.430487Z","steps":["trace[118181634] 'read index received' (duration: 120.796057ms)","trace[118181634] 'applied index is now lower than readState.Index' (duration: 475.667531ms)"],"step_count":2} Sep 12 05:55:54.431169 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430518Z","caller":"traceutil/trace.go:171","msg":"trace[1999104622] transaction","detail":"{read_only:false; response_revision:1237; number_of_response:1; }","duration":"603.727772ms","start":"2025-09-12T05:55:53.826773Z","end":"2025-09-12T05:55:54.430500Z","steps":["trace[1999104622] 'process raft request' (duration: 128.090929ms)","trace[1999104622] 'compare' (duration: 475.33439ms)"],"step_count":2} Sep 12 05:55:54.431622 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430630Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.826762Z","time spent":"603.817151ms","remote":"10.0.0.78:57156","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Sep 12 05:55:54.431622 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430701Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"596.678695ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/networkpolicies.crd.projectcalico.org\" ","response":"range_response_count:1 size:34255"} Sep 12 05:55:54.431622 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430723Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"569.140027ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/whisker:csr-creator\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:54.431622 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430735Z","caller":"traceutil/trace.go:171","msg":"trace[1383503239] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/networkpolicies.crd.projectcalico.org; range_end:; response_count:1; response_revision:1237; }","duration":"596.735933ms","start":"2025-09-12T05:55:53.833990Z","end":"2025-09-12T05:55:54.430726Z","steps":["trace[1383503239] 'agreement among raft nodes before linearized reading' (duration: 596.598053ms)"],"step_count":1} Sep 12 05:55:54.431770 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430775Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"468.213188ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-apiserver:csr-creator\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:54.431770 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430796Z","caller":"traceutil/trace.go:171","msg":"trace[1761371662] range","detail":"{range_begin:/registry/clusterrolebindings/calico-apiserver:csr-creator; range_end:; response_count:0; response_revision:1237; }","duration":"468.262913ms","start":"2025-09-12T05:55:53.962529Z","end":"2025-09-12T05:55:54.430792Z","steps":["trace[1761371662] 'agreement among raft nodes before linearized reading' (duration: 468.237354ms)"],"step_count":1} Sep 12 05:55:54.431770 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430809Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"518.928546ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/whisker:csr-creator\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:54.431770 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430814Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"527.174057ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/ingressclasses/\" range_end:\"/registry/ingressclasses0\" count_only:true ","response":"range_response_count:0 size:5"} Sep 12 05:55:54.431770 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430831Z","caller":"traceutil/trace.go:171","msg":"trace[146747234] range","detail":"{range_begin:/registry/clusterrolebindings/whisker:csr-creator; range_end:; response_count:0; response_revision:1237; }","duration":"518.961447ms","start":"2025-09-12T05:55:53.911863Z","end":"2025-09-12T05:55:54.430825Z","steps":["trace[146747234] 'agreement among raft nodes before linearized reading' (duration: 518.927654ms)"],"step_count":1} Sep 12 05:55:54.431892 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430838Z","caller":"traceutil/trace.go:171","msg":"trace[467886558] range","detail":"{range_begin:/registry/ingressclasses/; range_end:/registry/ingressclasses0; response_count:0; response_revision:1237; }","duration":"527.215636ms","start":"2025-09-12T05:55:53.903618Z","end":"2025-09-12T05:55:54.430833Z","steps":["trace[467886558] 'agreement among raft nodes before linearized reading' (duration: 527.175941ms)"],"step_count":1} Sep 12 05:55:54.431892 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430849Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.911855Z","time spent":"518.988539ms","remote":"10.0.0.78:57238","response type":"/etcdserverpb.KV/Range","request count":0,"request size":51,"response count":0,"response size":29,"request content":"key:\"/registry/clusterrolebindings/whisker:csr-creator\" "} Sep 12 05:55:54.431892 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430859Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.903610Z","time spent":"527.242447ms","remote":"10.0.0.78:57188","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":0,"response size":29,"request content":"key:\"/registry/ingressclasses/\" range_end:\"/registry/ingressclasses0\" count_only:true "} Sep 12 05:55:54.431892 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430770Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.833964Z","time spent":"596.794955ms","remote":"10.0.0.78:56902","response type":"/etcdserverpb.KV/Range","request count":0,"request size":96,"response count":1,"response size":34279,"request content":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/networkpolicies.crd.projectcalico.org\" "} Sep 12 05:55:54.432000 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.430823Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.962521Z","time spent":"468.296115ms","remote":"10.0.0.78:57238","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":0,"response size":29,"request content":"key:\"/registry/clusterrolebindings/calico-apiserver:csr-creator\" "} Sep 12 05:55:54.432000 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.430741Z","caller":"traceutil/trace.go:171","msg":"trace[10347190] range","detail":"{range_begin:/registry/clusterrolebindings/whisker:csr-creator; range_end:; response_count:0; response_revision:1237; }","duration":"569.16732ms","start":"2025-09-12T05:55:53.861568Z","end":"2025-09-12T05:55:54.430736Z","steps":["trace[10347190] 'agreement among raft nodes before linearized reading' (duration: 569.135459ms)"],"step_count":1} Sep 12 05:55:54.432000 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.431027Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-09-12T05:55:53.861558Z","time spent":"569.460264ms","remote":"10.0.0.78:57238","response type":"/etcdserverpb.KV/Range","request count":0,"request size":51,"response count":0,"response size":29,"request content":"key:\"/registry/clusterrolebindings/whisker:csr-creator\" "} Sep 12 05:55:54.889569 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.889072Z","caller":"traceutil/trace.go:171","msg":"trace[268811739] linearizableReadLoop","detail":"{readStateIndex:1454; appliedIndex:1453; }","duration":"116.950757ms","start":"2025-09-12T05:55:54.772103Z","end":"2025-09-12T05:55:54.889053Z","steps":["trace[268811739] 'read index received' (duration: 49.593276ms)","trace[268811739] 'applied index is now lower than readState.Index' (duration: 67.35695ms)"],"step_count":2} Sep 12 05:55:54.889569 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.889157Z","caller":"traceutil/trace.go:171","msg":"trace[1134944178] transaction","detail":"{read_only:false; response_revision:1239; number_of_response:1; }","duration":"118.391455ms","start":"2025-09-12T05:55:54.770759Z","end":"2025-09-12T05:55:54.889151Z","steps":["trace[1134944178] 'process raft request' (duration: 51.009326ms)","trace[1134944178] 'compare' (duration: 67.189924ms)"],"step_count":2} Sep 12 05:55:54.889569 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:54.889279Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.15865ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/calico-crds\" ","response":"range_response_count:1 size:1255"} Sep 12 05:55:54.889569 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:54.889342Z","caller":"traceutil/trace.go:171","msg":"trace[1027150767] range","detail":"{range_begin:/registry/clusterroles/calico-crds; range_end:; response_count:1; response_revision:1239; }","duration":"117.239675ms","start":"2025-09-12T05:55:54.772090Z","end":"2025-09-12T05:55:54.889329Z","steps":["trace[1027150767] 'agreement among raft nodes before linearized reading' (duration: 117.128735ms)"],"step_count":1} Sep 12 05:55:56.038693 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:56.038274Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"125.74967ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-node\" ","response":"range_response_count:1 size:692"} Sep 12 05:55:56.038693 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:56.038338Z","caller":"traceutil/trace.go:171","msg":"trace[1077262261] range","detail":"{range_begin:/registry/clusterrolebindings/calico-node; range_end:; response_count:1; response_revision:1242; }","duration":"125.823891ms","start":"2025-09-12T05:55:55.912500Z","end":"2025-09-12T05:55:56.038323Z","steps":["trace[1077262261] 'range keys from in-memory index tree' (duration: 125.645023ms)"],"step_count":1} Sep 12 05:55:56.686052 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:56.685706Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"123.988049ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/tigera-uisettingsgroup-getter\" ","response":"range_response_count:0 size:5"} Sep 12 05:55:56.686052 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:56.685771Z","caller":"traceutil/trace.go:171","msg":"trace[2043762880] range","detail":"{range_begin:/registry/clusterrolebindings/tigera-uisettingsgroup-getter; range_end:; response_count:0; response_revision:1243; }","duration":"124.067509ms","start":"2025-09-12T05:55:56.561688Z","end":"2025-09-12T05:55:56.685756Z","steps":["trace[2043762880] 'range keys from in-memory index tree' (duration: 123.950749ms)"],"step_count":1} Sep 12 05:55:56.686284 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:55:56.686018Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"134.190655ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/whiskers.operator.tigera.io\" ","response":"range_response_count:1 size:57010"} Sep 12 05:55:56.686284 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:56.686099Z","caller":"traceutil/trace.go:171","msg":"trace[933543203] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/whiskers.operator.tigera.io; range_end:; response_count:1; response_revision:1243; }","duration":"134.304571ms","start":"2025-09-12T05:55:56.551776Z","end":"2025-09-12T05:55:56.686081Z","steps":["trace[933543203] 'range keys from in-memory index tree' (duration: 133.897581ms)"],"step_count":1} Sep 12 05:55:58.676283 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:55:58.675878Z","caller":"traceutil/trace.go:171","msg":"trace[495920896] transaction","detail":"{read_only:false; response_revision:1248; number_of_response:1; }","duration":"116.488848ms","start":"2025-09-12T05:55:58.559371Z","end":"2025-09-12T05:55:58.675860Z","steps":["trace[495920896] 'process raft request' (duration: 63.476957ms)","trace[495920896] 'compare' (duration: 52.946968ms)"],"step_count":2} Sep 12 05:56:00.735060 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:56:00.734640Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"179.020479ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/stagedkubernetesnetworkpolicies.crd.projectcalico.org\" ","response":"range_response_count:1 size:20393"} Sep 12 05:56:00.735060 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:56:00.734701Z","caller":"traceutil/trace.go:171","msg":"trace[328089680] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/stagedkubernetesnetworkpolicies.crd.projectcalico.org; range_end:; response_count:1; response_revision:1257; }","duration":"179.114787ms","start":"2025-09-12T05:56:00.555571Z","end":"2025-09-12T05:56:00.734686Z","steps":["trace[328089680] 'range keys from in-memory index tree' (duration: 178.967418ms)"],"step_count":1} Sep 12 05:56:04.268813 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:56:04.268411Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"100.530089ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-apiserver-access-calico-crds\" ","response":"range_response_count:1 size:661"} Sep 12 05:56:04.268813 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:56:04.268479Z","caller":"traceutil/trace.go:171","msg":"trace[1580405199] range","detail":"{range_begin:/registry/clusterrolebindings/calico-apiserver-access-calico-crds; range_end:; response_count:1; response_revision:1310; }","duration":"100.621512ms","start":"2025-09-12T05:56:04.167841Z","end":"2025-09-12T05:56:04.268463Z","steps":["trace[1580405199] 'range keys from in-memory index tree' (duration: 100.394574ms)"],"step_count":1} Sep 12 05:56:16.235326 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:56:16.235007Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"109.463462ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/csi-node-driver\" ","response":"range_response_count:1 size:447"} Sep 12 05:56:16.235326 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:56:16.235057Z","caller":"traceutil/trace.go:171","msg":"trace[890161745] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/csi-node-driver; range_end:; response_count:1; response_revision:1356; }","duration":"109.527764ms","start":"2025-09-12T05:56:16.125519Z","end":"2025-09-12T05:56:16.235047Z","steps":["trace[890161745] 'range keys from in-memory index tree' (duration: 109.384884ms)"],"step_count":1} Sep 12 05:56:21.353090 etcd-wrapper[1820]: {"level":"warn","ts":"2025-09-12T05:56:21.352705Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"158.875305ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/felixconfigurations.crd.projectcalico.org\" ","response":"range_response_count:1 size:55540"} Sep 12 05:56:21.353090 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:56:21.352776Z","caller":"traceutil/trace.go:171","msg":"trace[1205259967] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/felixconfigurations.crd.projectcalico.org; range_end:; response_count:1; response_revision:1381; }","duration":"158.969774ms","start":"2025-09-12T05:56:21.193788Z","end":"2025-09-12T05:56:21.352758Z","steps":["trace[1205259967] 'range keys from in-memory index tree' (duration: 158.695456ms)"],"step_count":1} Sep 12 05:56:22.615806 etcd-wrapper[1820]: {"level":"info","ts":"2025-09-12T05:56:22.615281Z","caller":"traceutil/trace.go:171","msg":"trace[352127171] transaction","detail":"{read_only:false; response_revision:1382; number_of_response:1; }","duration":"117.570049ms","start":"2025-09-12T05:56:22.497691Z","end":"2025-09-12T05:56:22.615262Z","steps":["trace[352127171] 'process raft request' (duration: 117.455833ms)"],"step_count":1}