Feb 13 19:36:25.877562 kernel: Linux version 6.6.74-flatcar (build@pony-truck.infra.kinvolk.io) (x86_64-cros-linux-gnu-gcc (Gentoo Hardened 13.3.1_p20240614 p1) 13.3.1 20240614, GNU ld (Gentoo 2.42 p6) 2.42.0) #1 SMP PREEMPT_DYNAMIC Thu Feb 13 17:44:05 -00 2025 Feb 13 19:36:25.877583 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=ed9b5d8ea73d2e47b8decea8124089e04dd398ef43013c1b1a5809314044b1c3 Feb 13 19:36:25.877594 kernel: BIOS-provided physical RAM map: Feb 13 19:36:25.877600 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable Feb 13 19:36:25.877606 kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved Feb 13 19:36:25.877612 kernel: BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved Feb 13 19:36:25.877618 kernel: BIOS-e820: [mem 0x0000000000100000-0x000000009cfdbfff] usable Feb 13 19:36:25.877625 kernel: BIOS-e820: [mem 0x000000009cfdc000-0x000000009cffffff] reserved Feb 13 19:36:25.877630 kernel: BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved Feb 13 19:36:25.877639 kernel: BIOS-e820: [mem 0x00000000fed1c000-0x00000000fed1ffff] reserved Feb 13 19:36:25.877645 kernel: BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved Feb 13 19:36:25.877650 kernel: BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved Feb 13 19:36:25.877656 kernel: BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved Feb 13 19:36:25.877662 kernel: NX (Execute Disable) protection: active Feb 13 19:36:25.877669 kernel: APIC: Static calls initialized Feb 13 19:36:25.877678 kernel: SMBIOS 2.8 present. Feb 13 19:36:25.877685 kernel: DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 Feb 13 19:36:25.877691 kernel: Hypervisor detected: KVM Feb 13 19:36:25.877697 kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00 Feb 13 19:36:25.877704 kernel: kvm-clock: using sched offset of 2280704271 cycles Feb 13 19:36:25.877777 kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns Feb 13 19:36:25.877785 kernel: tsc: Detected 2794.750 MHz processor Feb 13 19:36:25.877792 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Feb 13 19:36:25.877799 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Feb 13 19:36:25.877806 kernel: last_pfn = 0x9cfdc max_arch_pfn = 0x400000000 Feb 13 19:36:25.877816 kernel: MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs Feb 13 19:36:25.877822 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Feb 13 19:36:25.877829 kernel: Using GB pages for direct mapping Feb 13 19:36:25.877835 kernel: ACPI: Early table checksum verification disabled Feb 13 19:36:25.877842 kernel: ACPI: RSDP 0x00000000000F59D0 000014 (v00 BOCHS ) Feb 13 19:36:25.877849 kernel: ACPI: RSDT 0x000000009CFE2408 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877855 kernel: ACPI: FACP 0x000000009CFE21E8 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877862 kernel: ACPI: DSDT 0x000000009CFE0040 0021A8 (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877870 kernel: ACPI: FACS 0x000000009CFE0000 000040 Feb 13 19:36:25.877877 kernel: ACPI: APIC 0x000000009CFE22DC 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877884 kernel: ACPI: HPET 0x000000009CFE236C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877890 kernel: ACPI: MCFG 0x000000009CFE23A4 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877897 kernel: ACPI: WAET 0x000000009CFE23E0 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) Feb 13 19:36:25.877903 kernel: ACPI: Reserving FACP table memory at [mem 0x9cfe21e8-0x9cfe22db] Feb 13 19:36:25.877910 kernel: ACPI: Reserving DSDT table memory at [mem 0x9cfe0040-0x9cfe21e7] Feb 13 19:36:25.877920 kernel: ACPI: Reserving FACS table memory at [mem 0x9cfe0000-0x9cfe003f] Feb 13 19:36:25.877928 kernel: ACPI: Reserving APIC table memory at [mem 0x9cfe22dc-0x9cfe236b] Feb 13 19:36:25.877935 kernel: ACPI: Reserving HPET table memory at [mem 0x9cfe236c-0x9cfe23a3] Feb 13 19:36:25.877942 kernel: ACPI: Reserving MCFG table memory at [mem 0x9cfe23a4-0x9cfe23df] Feb 13 19:36:25.877949 kernel: ACPI: Reserving WAET table memory at [mem 0x9cfe23e0-0x9cfe2407] Feb 13 19:36:25.877955 kernel: No NUMA configuration found Feb 13 19:36:25.877962 kernel: Faking a node at [mem 0x0000000000000000-0x000000009cfdbfff] Feb 13 19:36:25.877969 kernel: NODE_DATA(0) allocated [mem 0x9cfd6000-0x9cfdbfff] Feb 13 19:36:25.877978 kernel: Zone ranges: Feb 13 19:36:25.877985 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Feb 13 19:36:25.877992 kernel: DMA32 [mem 0x0000000001000000-0x000000009cfdbfff] Feb 13 19:36:25.877998 kernel: Normal empty Feb 13 19:36:25.878005 kernel: Movable zone start for each node Feb 13 19:36:25.878012 kernel: Early memory node ranges Feb 13 19:36:25.878018 kernel: node 0: [mem 0x0000000000001000-0x000000000009efff] Feb 13 19:36:25.878025 kernel: node 0: [mem 0x0000000000100000-0x000000009cfdbfff] Feb 13 19:36:25.878032 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000009cfdbfff] Feb 13 19:36:25.878041 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Feb 13 19:36:25.878048 kernel: On node 0, zone DMA: 97 pages in unavailable ranges Feb 13 19:36:25.878054 kernel: On node 0, zone DMA32: 12324 pages in unavailable ranges Feb 13 19:36:25.878061 kernel: ACPI: PM-Timer IO Port: 0x608 Feb 13 19:36:25.878068 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Feb 13 19:36:25.878075 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Feb 13 19:36:25.878082 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Feb 13 19:36:25.878088 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Feb 13 19:36:25.878095 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Feb 13 19:36:25.878104 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Feb 13 19:36:25.878111 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Feb 13 19:36:25.878118 kernel: ACPI: Using ACPI (MADT) for SMP configuration information Feb 13 19:36:25.878125 kernel: ACPI: HPET id: 0x8086a201 base: 0xfed00000 Feb 13 19:36:25.878132 kernel: TSC deadline timer available Feb 13 19:36:25.878138 kernel: smpboot: Allowing 4 CPUs, 0 hotplug CPUs Feb 13 19:36:25.878145 kernel: kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() Feb 13 19:36:25.878152 kernel: kvm-guest: KVM setup pv remote TLB flush Feb 13 19:36:25.878159 kernel: kvm-guest: setup PV sched yield Feb 13 19:36:25.878165 kernel: [mem 0xc0000000-0xfed1bfff] available for PCI devices Feb 13 19:36:25.878174 kernel: Booting paravirtualized kernel on KVM Feb 13 19:36:25.878181 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns Feb 13 19:36:25.878188 kernel: setup_percpu: NR_CPUS:512 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 Feb 13 19:36:25.878195 kernel: percpu: Embedded 58 pages/cpu s197032 r8192 d32344 u524288 Feb 13 19:36:25.878202 kernel: pcpu-alloc: s197032 r8192 d32344 u524288 alloc=1*2097152 Feb 13 19:36:25.878208 kernel: pcpu-alloc: [0] 0 1 2 3 Feb 13 19:36:25.878215 kernel: kvm-guest: PV spinlocks enabled Feb 13 19:36:25.878222 kernel: PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) Feb 13 19:36:25.878230 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=ed9b5d8ea73d2e47b8decea8124089e04dd398ef43013c1b1a5809314044b1c3 Feb 13 19:36:25.878239 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. Feb 13 19:36:25.878246 kernel: random: crng init done Feb 13 19:36:25.878253 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Feb 13 19:36:25.878260 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Feb 13 19:36:25.878267 kernel: Fallback order for Node 0: 0 Feb 13 19:36:25.878273 kernel: Built 1 zonelists, mobility grouping on. Total pages: 632732 Feb 13 19:36:25.878280 kernel: Policy zone: DMA32 Feb 13 19:36:25.878287 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Feb 13 19:36:25.878296 kernel: Memory: 2434592K/2571752K available (12288K kernel code, 2301K rwdata, 22736K rodata, 42976K init, 2216K bss, 136900K reserved, 0K cma-reserved) Feb 13 19:36:25.878303 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Feb 13 19:36:25.878319 kernel: ftrace: allocating 37923 entries in 149 pages Feb 13 19:36:25.878326 kernel: ftrace: allocated 149 pages with 4 groups Feb 13 19:36:25.878333 kernel: Dynamic Preempt: voluntary Feb 13 19:36:25.878341 kernel: rcu: Preemptible hierarchical RCU implementation. Feb 13 19:36:25.878348 kernel: rcu: RCU event tracing is enabled. Feb 13 19:36:25.878355 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Feb 13 19:36:25.878362 kernel: Trampoline variant of Tasks RCU enabled. Feb 13 19:36:25.878371 kernel: Rude variant of Tasks RCU enabled. Feb 13 19:36:25.878378 kernel: Tracing variant of Tasks RCU enabled. Feb 13 19:36:25.878385 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Feb 13 19:36:25.878391 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Feb 13 19:36:25.878398 kernel: NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16 Feb 13 19:36:25.878405 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Feb 13 19:36:25.878412 kernel: Console: colour VGA+ 80x25 Feb 13 19:36:25.878419 kernel: printk: console [ttyS0] enabled Feb 13 19:36:25.878425 kernel: ACPI: Core revision 20230628 Feb 13 19:36:25.878435 kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns Feb 13 19:36:25.878442 kernel: APIC: Switch to symmetric I/O mode setup Feb 13 19:36:25.878449 kernel: x2apic enabled Feb 13 19:36:25.878456 kernel: APIC: Switched APIC routing to: physical x2apic Feb 13 19:36:25.878463 kernel: kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() Feb 13 19:36:25.878470 kernel: kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() Feb 13 19:36:25.878477 kernel: kvm-guest: setup PV IPIs Feb 13 19:36:25.878493 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Feb 13 19:36:25.878500 kernel: tsc: Marking TSC unstable due to TSCs unsynchronized Feb 13 19:36:25.878507 kernel: Calibrating delay loop (skipped) preset value.. 5589.50 BogoMIPS (lpj=2794750) Feb 13 19:36:25.878514 kernel: x86/cpu: User Mode Instruction Prevention (UMIP) activated Feb 13 19:36:25.878521 kernel: Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 Feb 13 19:36:25.878530 kernel: Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 Feb 13 19:36:25.878538 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Feb 13 19:36:25.878545 kernel: Spectre V2 : Mitigation: Retpolines Feb 13 19:36:25.878552 kernel: Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch Feb 13 19:36:25.878559 kernel: Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT Feb 13 19:36:25.878569 kernel: Spectre V2 : Enabling Speculation Barrier for firmware calls Feb 13 19:36:25.878576 kernel: RETBleed: Mitigation: untrained return thunk Feb 13 19:36:25.878583 kernel: Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier Feb 13 19:36:25.878590 kernel: Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl Feb 13 19:36:25.878598 kernel: Speculative Return Stack Overflow: IBPB-extending microcode not applied! Feb 13 19:36:25.878605 kernel: Speculative Return Stack Overflow: WARNING: See https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for mitigation options. Feb 13 19:36:25.878613 kernel: Speculative Return Stack Overflow: Vulnerable: Safe RET, no microcode Feb 13 19:36:25.878620 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Feb 13 19:36:25.878629 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Feb 13 19:36:25.878636 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Feb 13 19:36:25.878644 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Feb 13 19:36:25.878651 kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. Feb 13 19:36:25.878658 kernel: Freeing SMP alternatives memory: 32K Feb 13 19:36:25.878665 kernel: pid_max: default: 32768 minimum: 301 Feb 13 19:36:25.878672 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,integrity Feb 13 19:36:25.878679 kernel: landlock: Up and running. Feb 13 19:36:25.878686 kernel: SELinux: Initializing. Feb 13 19:36:25.878696 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Feb 13 19:36:25.878703 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Feb 13 19:36:25.878721 kernel: smpboot: CPU0: AMD EPYC 7402P 24-Core Processor (family: 0x17, model: 0x31, stepping: 0x0) Feb 13 19:36:25.878728 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Feb 13 19:36:25.878736 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Feb 13 19:36:25.878743 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Feb 13 19:36:25.878750 kernel: Performance Events: Fam17h+ core perfctr, AMD PMU driver. Feb 13 19:36:25.878757 kernel: ... version: 0 Feb 13 19:36:25.878764 kernel: ... bit width: 48 Feb 13 19:36:25.878774 kernel: ... generic registers: 6 Feb 13 19:36:25.878781 kernel: ... value mask: 0000ffffffffffff Feb 13 19:36:25.878788 kernel: ... max period: 00007fffffffffff Feb 13 19:36:25.878795 kernel: ... fixed-purpose events: 0 Feb 13 19:36:25.878802 kernel: ... event mask: 000000000000003f Feb 13 19:36:25.878810 kernel: signal: max sigframe size: 1776 Feb 13 19:36:25.878817 kernel: rcu: Hierarchical SRCU implementation. Feb 13 19:36:25.878824 kernel: rcu: Max phase no-delay instances is 400. Feb 13 19:36:25.878831 kernel: smp: Bringing up secondary CPUs ... Feb 13 19:36:25.878841 kernel: smpboot: x86: Booting SMP configuration: Feb 13 19:36:25.878848 kernel: .... node #0, CPUs: #1 #2 #3 Feb 13 19:36:25.878855 kernel: smp: Brought up 1 node, 4 CPUs Feb 13 19:36:25.878862 kernel: smpboot: Max logical packages: 1 Feb 13 19:36:25.878869 kernel: smpboot: Total of 4 processors activated (22358.00 BogoMIPS) Feb 13 19:36:25.878876 kernel: devtmpfs: initialized Feb 13 19:36:25.878883 kernel: x86/mm: Memory block size: 128MB Feb 13 19:36:25.878890 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Feb 13 19:36:25.878898 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Feb 13 19:36:25.878907 kernel: pinctrl core: initialized pinctrl subsystem Feb 13 19:36:25.878914 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Feb 13 19:36:25.878921 kernel: audit: initializing netlink subsys (disabled) Feb 13 19:36:25.878929 kernel: audit: type=2000 audit(1739475385.538:1): state=initialized audit_enabled=0 res=1 Feb 13 19:36:25.878936 kernel: thermal_sys: Registered thermal governor 'step_wise' Feb 13 19:36:25.878943 kernel: thermal_sys: Registered thermal governor 'user_space' Feb 13 19:36:25.878950 kernel: cpuidle: using governor menu Feb 13 19:36:25.878957 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Feb 13 19:36:25.878964 kernel: dca service started, version 1.12.1 Feb 13 19:36:25.878973 kernel: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xb0000000-0xbfffffff] (base 0xb0000000) Feb 13 19:36:25.878980 kernel: PCI: MMCONFIG at [mem 0xb0000000-0xbfffffff] reserved as E820 entry Feb 13 19:36:25.878988 kernel: PCI: Using configuration type 1 for base access Feb 13 19:36:25.878995 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Feb 13 19:36:25.879002 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Feb 13 19:36:25.879009 kernel: HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page Feb 13 19:36:25.879016 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Feb 13 19:36:25.879024 kernel: HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page Feb 13 19:36:25.879031 kernel: ACPI: Added _OSI(Module Device) Feb 13 19:36:25.879040 kernel: ACPI: Added _OSI(Processor Device) Feb 13 19:36:25.879047 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) Feb 13 19:36:25.879054 kernel: ACPI: Added _OSI(Processor Aggregator Device) Feb 13 19:36:25.879061 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Feb 13 19:36:25.879068 kernel: ACPI: _OSC evaluation for CPUs failed, trying _PDC Feb 13 19:36:25.879075 kernel: ACPI: Interpreter enabled Feb 13 19:36:25.879082 kernel: ACPI: PM: (supports S0 S3 S5) Feb 13 19:36:25.879090 kernel: ACPI: Using IOAPIC for interrupt routing Feb 13 19:36:25.879097 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Feb 13 19:36:25.879106 kernel: PCI: Using E820 reservations for host bridge windows Feb 13 19:36:25.879113 kernel: ACPI: Enabled 2 GPEs in block 00 to 3F Feb 13 19:36:25.879120 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Feb 13 19:36:25.879312 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Feb 13 19:36:25.879443 kernel: acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR] Feb 13 19:36:25.879574 kernel: acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability] Feb 13 19:36:25.879599 kernel: PCI host bridge to bus 0000:00 Feb 13 19:36:25.879817 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Feb 13 19:36:25.879932 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Feb 13 19:36:25.880041 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Feb 13 19:36:25.880150 kernel: pci_bus 0000:00: root bus resource [mem 0x9d000000-0xafffffff window] Feb 13 19:36:25.880259 kernel: pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] Feb 13 19:36:25.880379 kernel: pci_bus 0000:00: root bus resource [mem 0x100000000-0x8ffffffff window] Feb 13 19:36:25.880490 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Feb 13 19:36:25.880634 kernel: pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 Feb 13 19:36:25.880788 kernel: pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 Feb 13 19:36:25.880953 kernel: pci 0000:00:01.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref] Feb 13 19:36:25.881116 kernel: pci 0000:00:01.0: reg 0x18: [mem 0xfebd0000-0xfebd0fff] Feb 13 19:36:25.881243 kernel: pci 0000:00:01.0: reg 0x30: [mem 0xfebc0000-0xfebcffff pref] Feb 13 19:36:25.881408 kernel: pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Feb 13 19:36:25.881542 kernel: pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 Feb 13 19:36:25.881667 kernel: pci 0000:00:02.0: reg 0x10: [io 0xc0c0-0xc0df] Feb 13 19:36:25.881810 kernel: pci 0000:00:02.0: reg 0x14: [mem 0xfebd1000-0xfebd1fff] Feb 13 19:36:25.881930 kernel: pci 0000:00:02.0: reg 0x20: [mem 0xfe000000-0xfe003fff 64bit pref] Feb 13 19:36:25.882057 kernel: pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 Feb 13 19:36:25.882176 kernel: pci 0000:00:03.0: reg 0x10: [io 0xc000-0xc07f] Feb 13 19:36:25.882295 kernel: pci 0000:00:03.0: reg 0x14: [mem 0xfebd2000-0xfebd2fff] Feb 13 19:36:25.882438 kernel: pci 0000:00:03.0: reg 0x20: [mem 0xfe004000-0xfe007fff 64bit pref] Feb 13 19:36:25.882606 kernel: pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 Feb 13 19:36:25.882743 kernel: pci 0000:00:04.0: reg 0x10: [io 0xc0e0-0xc0ff] Feb 13 19:36:25.882866 kernel: pci 0000:00:04.0: reg 0x14: [mem 0xfebd3000-0xfebd3fff] Feb 13 19:36:25.882991 kernel: pci 0000:00:04.0: reg 0x20: [mem 0xfe008000-0xfe00bfff 64bit pref] Feb 13 19:36:25.883111 kernel: pci 0000:00:04.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] Feb 13 19:36:25.883239 kernel: pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 Feb 13 19:36:25.883386 kernel: pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO Feb 13 19:36:25.883537 kernel: pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 Feb 13 19:36:25.883657 kernel: pci 0000:00:1f.2: reg 0x20: [io 0xc100-0xc11f] Feb 13 19:36:25.883808 kernel: pci 0000:00:1f.2: reg 0x24: [mem 0xfebd4000-0xfebd4fff] Feb 13 19:36:25.883937 kernel: pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 Feb 13 19:36:25.884055 kernel: pci 0000:00:1f.3: reg 0x20: [io 0x0700-0x073f] Feb 13 19:36:25.884065 kernel: ACPI: PCI: Interrupt link LNKA configured for IRQ 10 Feb 13 19:36:25.884077 kernel: ACPI: PCI: Interrupt link LNKB configured for IRQ 10 Feb 13 19:36:25.884084 kernel: ACPI: PCI: Interrupt link LNKC configured for IRQ 11 Feb 13 19:36:25.884091 kernel: ACPI: PCI: Interrupt link LNKD configured for IRQ 11 Feb 13 19:36:25.884098 kernel: ACPI: PCI: Interrupt link LNKE configured for IRQ 10 Feb 13 19:36:25.884105 kernel: ACPI: PCI: Interrupt link LNKF configured for IRQ 10 Feb 13 19:36:25.884113 kernel: ACPI: PCI: Interrupt link LNKG configured for IRQ 11 Feb 13 19:36:25.884120 kernel: ACPI: PCI: Interrupt link LNKH configured for IRQ 11 Feb 13 19:36:25.884127 kernel: ACPI: PCI: Interrupt link GSIA configured for IRQ 16 Feb 13 19:36:25.884134 kernel: ACPI: PCI: Interrupt link GSIB configured for IRQ 17 Feb 13 19:36:25.884143 kernel: ACPI: PCI: Interrupt link GSIC configured for IRQ 18 Feb 13 19:36:25.884150 kernel: ACPI: PCI: Interrupt link GSID configured for IRQ 19 Feb 13 19:36:25.884157 kernel: ACPI: PCI: Interrupt link GSIE configured for IRQ 20 Feb 13 19:36:25.884164 kernel: ACPI: PCI: Interrupt link GSIF configured for IRQ 21 Feb 13 19:36:25.884171 kernel: ACPI: PCI: Interrupt link GSIG configured for IRQ 22 Feb 13 19:36:25.884178 kernel: ACPI: PCI: Interrupt link GSIH configured for IRQ 23 Feb 13 19:36:25.884185 kernel: iommu: Default domain type: Translated Feb 13 19:36:25.884192 kernel: iommu: DMA domain TLB invalidation policy: lazy mode Feb 13 19:36:25.884199 kernel: PCI: Using ACPI for IRQ routing Feb 13 19:36:25.884209 kernel: PCI: pci_cache_line_size set to 64 bytes Feb 13 19:36:25.884216 kernel: e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] Feb 13 19:36:25.884223 kernel: e820: reserve RAM buffer [mem 0x9cfdc000-0x9fffffff] Feb 13 19:36:25.884352 kernel: pci 0000:00:01.0: vgaarb: setting as boot VGA device Feb 13 19:36:25.884471 kernel: pci 0000:00:01.0: vgaarb: bridge control possible Feb 13 19:36:25.884590 kernel: pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Feb 13 19:36:25.884599 kernel: vgaarb: loaded Feb 13 19:36:25.884606 kernel: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Feb 13 19:36:25.884617 kernel: hpet0: 3 comparators, 64-bit 100.000000 MHz counter Feb 13 19:36:25.884624 kernel: clocksource: Switched to clocksource kvm-clock Feb 13 19:36:25.884631 kernel: VFS: Disk quotas dquot_6.6.0 Feb 13 19:36:25.884638 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Feb 13 19:36:25.884645 kernel: pnp: PnP ACPI init Feb 13 19:36:25.884790 kernel: system 00:05: [mem 0xb0000000-0xbfffffff window] has been reserved Feb 13 19:36:25.884801 kernel: pnp: PnP ACPI: found 6 devices Feb 13 19:36:25.884809 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Feb 13 19:36:25.884819 kernel: NET: Registered PF_INET protocol family Feb 13 19:36:25.884826 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Feb 13 19:36:25.884834 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Feb 13 19:36:25.884841 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Feb 13 19:36:25.884848 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Feb 13 19:36:25.884855 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Feb 13 19:36:25.884862 kernel: TCP: Hash tables configured (established 32768 bind 32768) Feb 13 19:36:25.884869 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Feb 13 19:36:25.884876 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Feb 13 19:36:25.884886 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Feb 13 19:36:25.884893 kernel: NET: Registered PF_XDP protocol family Feb 13 19:36:25.885005 kernel: pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] Feb 13 19:36:25.885113 kernel: pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] Feb 13 19:36:25.885222 kernel: pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] Feb 13 19:36:25.885342 kernel: pci_bus 0000:00: resource 7 [mem 0x9d000000-0xafffffff window] Feb 13 19:36:25.885452 kernel: pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window] Feb 13 19:36:25.885560 kernel: pci_bus 0000:00: resource 9 [mem 0x100000000-0x8ffffffff window] Feb 13 19:36:25.885572 kernel: PCI: CLS 0 bytes, default 64 Feb 13 19:36:25.885580 kernel: Initialise system trusted keyrings Feb 13 19:36:25.885587 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Feb 13 19:36:25.885594 kernel: Key type asymmetric registered Feb 13 19:36:25.885601 kernel: Asymmetric key parser 'x509' registered Feb 13 19:36:25.885608 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251) Feb 13 19:36:25.885616 kernel: io scheduler mq-deadline registered Feb 13 19:36:25.885623 kernel: io scheduler kyber registered Feb 13 19:36:25.885630 kernel: io scheduler bfq registered Feb 13 19:36:25.885639 kernel: ioatdma: Intel(R) QuickData Technology Driver 5.00 Feb 13 19:36:25.885647 kernel: ACPI: \_SB_.GSIG: Enabled at IRQ 22 Feb 13 19:36:25.885654 kernel: ACPI: \_SB_.GSIH: Enabled at IRQ 23 Feb 13 19:36:25.885662 kernel: ACPI: \_SB_.GSIE: Enabled at IRQ 20 Feb 13 19:36:25.885669 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Feb 13 19:36:25.885676 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Feb 13 19:36:25.885684 kernel: i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Feb 13 19:36:25.885691 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Feb 13 19:36:25.885698 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Feb 13 19:36:25.885708 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 Feb 13 19:36:25.885845 kernel: rtc_cmos 00:04: RTC can wake from S4 Feb 13 19:36:25.885966 kernel: rtc_cmos 00:04: registered as rtc0 Feb 13 19:36:25.886080 kernel: rtc_cmos 00:04: setting system clock to 2025-02-13T19:36:25 UTC (1739475385) Feb 13 19:36:25.886193 kernel: rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram, hpet irqs Feb 13 19:36:25.886202 kernel: amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled Feb 13 19:36:25.886209 kernel: NET: Registered PF_INET6 protocol family Feb 13 19:36:25.886216 kernel: Segment Routing with IPv6 Feb 13 19:36:25.886227 kernel: In-situ OAM (IOAM) with IPv6 Feb 13 19:36:25.886234 kernel: NET: Registered PF_PACKET protocol family Feb 13 19:36:25.886241 kernel: Key type dns_resolver registered Feb 13 19:36:25.886248 kernel: IPI shorthand broadcast: enabled Feb 13 19:36:25.886256 kernel: sched_clock: Marking stable (573002855, 104653636)->(692296506, -14640015) Feb 13 19:36:25.886263 kernel: registered taskstats version 1 Feb 13 19:36:25.886270 kernel: Loading compiled-in X.509 certificates Feb 13 19:36:25.886278 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.6.74-flatcar: 0cc219a306b9e46e583adebba1820decbdc4307b' Feb 13 19:36:25.886285 kernel: Key type .fscrypt registered Feb 13 19:36:25.886294 kernel: Key type fscrypt-provisioning registered Feb 13 19:36:25.886301 kernel: ima: No TPM chip found, activating TPM-bypass! Feb 13 19:36:25.886317 kernel: ima: Allocated hash algorithm: sha1 Feb 13 19:36:25.886324 kernel: ima: No architecture policies found Feb 13 19:36:25.886332 kernel: clk: Disabling unused clocks Feb 13 19:36:25.886339 kernel: Freeing unused kernel image (initmem) memory: 42976K Feb 13 19:36:25.886346 kernel: Write protecting the kernel read-only data: 36864k Feb 13 19:36:25.886353 kernel: Freeing unused kernel image (rodata/data gap) memory: 1840K Feb 13 19:36:25.886360 kernel: Run /init as init process Feb 13 19:36:25.886370 kernel: with arguments: Feb 13 19:36:25.886377 kernel: /init Feb 13 19:36:25.886384 kernel: with environment: Feb 13 19:36:25.886391 kernel: HOME=/ Feb 13 19:36:25.886398 kernel: TERM=linux Feb 13 19:36:25.886405 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a Feb 13 19:36:25.886414 systemd[1]: systemd 255 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified) Feb 13 19:36:25.886423 systemd[1]: Detected virtualization kvm. Feb 13 19:36:25.886433 systemd[1]: Detected architecture x86-64. Feb 13 19:36:25.886441 systemd[1]: Running in initrd. Feb 13 19:36:25.886448 systemd[1]: No hostname configured, using default hostname. Feb 13 19:36:25.886456 systemd[1]: Hostname set to . Feb 13 19:36:25.886464 systemd[1]: Initializing machine ID from VM UUID. Feb 13 19:36:25.886471 systemd[1]: Queued start job for default target initrd.target. Feb 13 19:36:25.886479 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Feb 13 19:36:25.886487 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Feb 13 19:36:25.886498 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Feb 13 19:36:25.886516 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Feb 13 19:36:25.886526 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Feb 13 19:36:25.886535 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Feb 13 19:36:25.886545 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... Feb 13 19:36:25.886555 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... Feb 13 19:36:25.886563 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Feb 13 19:36:25.886571 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Feb 13 19:36:25.886579 systemd[1]: Reached target paths.target - Path Units. Feb 13 19:36:25.886587 systemd[1]: Reached target slices.target - Slice Units. Feb 13 19:36:25.886594 systemd[1]: Reached target swap.target - Swaps. Feb 13 19:36:25.886602 systemd[1]: Reached target timers.target - Timer Units. Feb 13 19:36:25.886610 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Feb 13 19:36:25.886620 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Feb 13 19:36:25.886628 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Feb 13 19:36:25.886636 systemd[1]: Listening on systemd-journald.socket - Journal Socket. Feb 13 19:36:25.886644 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Feb 13 19:36:25.886652 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Feb 13 19:36:25.886660 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Feb 13 19:36:25.886668 systemd[1]: Reached target sockets.target - Socket Units. Feb 13 19:36:25.886676 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Feb 13 19:36:25.886684 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Feb 13 19:36:25.886695 systemd[1]: Finished network-cleanup.service - Network Cleanup. Feb 13 19:36:25.886704 systemd[1]: Starting systemd-fsck-usr.service... Feb 13 19:36:25.886733 systemd[1]: Starting systemd-journald.service - Journal Service... Feb 13 19:36:25.886741 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Feb 13 19:36:25.886749 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Feb 13 19:36:25.886757 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Feb 13 19:36:25.886765 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Feb 13 19:36:25.886773 systemd[1]: Finished systemd-fsck-usr.service. Feb 13 19:36:25.886801 systemd-journald[194]: Collecting audit messages is disabled. Feb 13 19:36:25.886821 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Feb 13 19:36:25.886832 systemd-journald[194]: Journal started Feb 13 19:36:25.886851 systemd-journald[194]: Runtime Journal (/run/log/journal/428f8b7b87cd429097bd2d52a56c643c) is 6.0M, max 48.4M, 42.3M free. Feb 13 19:36:25.881359 systemd-modules-load[195]: Inserted module 'overlay' Feb 13 19:36:25.920076 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Feb 13 19:36:25.920090 kernel: Bridge firewalling registered Feb 13 19:36:25.907884 systemd-modules-load[195]: Inserted module 'br_netfilter' Feb 13 19:36:25.923132 systemd[1]: Started systemd-journald.service - Journal Service. Feb 13 19:36:25.923664 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Feb 13 19:36:25.926258 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Feb 13 19:36:25.928922 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Feb 13 19:36:25.948923 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Feb 13 19:36:25.952378 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Feb 13 19:36:25.955774 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Feb 13 19:36:25.957346 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Feb 13 19:36:25.961863 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Feb 13 19:36:25.966579 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Feb 13 19:36:25.969843 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Feb 13 19:36:25.972138 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Feb 13 19:36:25.976624 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Feb 13 19:36:25.983555 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Feb 13 19:36:25.986374 dracut-cmdline[224]: dracut-dracut-053 Feb 13 19:36:25.989706 dracut-cmdline[224]: Using kernel command line parameters: rd.driver.pre=btrfs 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=ed9b5d8ea73d2e47b8decea8124089e04dd398ef43013c1b1a5809314044b1c3 Feb 13 19:36:26.012185 systemd-resolved[229]: Positive Trust Anchors: Feb 13 19:36:26.012204 systemd-resolved[229]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Feb 13 19:36:26.012234 systemd-resolved[229]: 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 Feb 13 19:36:26.014686 systemd-resolved[229]: Defaulting to hostname 'linux'. Feb 13 19:36:26.015741 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Feb 13 19:36:26.022033 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Feb 13 19:36:26.087751 kernel: SCSI subsystem initialized Feb 13 19:36:26.097749 kernel: Loading iSCSI transport class v2.0-870. Feb 13 19:36:26.108740 kernel: iscsi: registered transport (tcp) Feb 13 19:36:26.133738 kernel: iscsi: registered transport (qla4xxx) Feb 13 19:36:26.133779 kernel: QLogic iSCSI HBA Driver Feb 13 19:36:26.185877 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Feb 13 19:36:26.193953 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Feb 13 19:36:26.220091 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Feb 13 19:36:26.220123 kernel: device-mapper: uevent: version 1.0.3 Feb 13 19:36:26.221351 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com Feb 13 19:36:26.262746 kernel: raid6: avx2x4 gen() 29217 MB/s Feb 13 19:36:26.279756 kernel: raid6: avx2x2 gen() 27197 MB/s Feb 13 19:36:26.296934 kernel: raid6: avx2x1 gen() 25854 MB/s Feb 13 19:36:26.296954 kernel: raid6: using algorithm avx2x4 gen() 29217 MB/s Feb 13 19:36:26.314810 kernel: raid6: .... xor() 7530 MB/s, rmw enabled Feb 13 19:36:26.314824 kernel: raid6: using avx2x2 recovery algorithm Feb 13 19:36:26.335757 kernel: xor: automatically using best checksumming function avx Feb 13 19:36:26.485772 kernel: Btrfs loaded, zoned=no, fsverity=no Feb 13 19:36:26.499590 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Feb 13 19:36:26.511866 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Feb 13 19:36:26.525282 systemd-udevd[414]: Using default interface naming scheme 'v255'. Feb 13 19:36:26.530893 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Feb 13 19:36:26.538846 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Feb 13 19:36:26.556759 dracut-pre-trigger[420]: rd.md=0: removing MD RAID activation Feb 13 19:36:26.591451 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Feb 13 19:36:26.602887 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Feb 13 19:36:26.665250 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Feb 13 19:36:26.675893 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Feb 13 19:36:26.687477 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Feb 13 19:36:26.689502 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Feb 13 19:36:26.693761 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Feb 13 19:36:26.696120 systemd[1]: Reached target remote-fs.target - Remote File Systems. Feb 13 19:36:26.702727 kernel: virtio_blk virtio1: 4/0/0 default/read/poll queues Feb 13 19:36:26.733848 kernel: cryptd: max_cpu_qlen set to 1000 Feb 13 19:36:26.733863 kernel: virtio_blk virtio1: [vda] 9289728 512-byte logical blocks (4.76 GB/4.43 GiB) Feb 13 19:36:26.734003 kernel: AVX2 version of gcm_enc/dec engaged. Feb 13 19:36:26.734014 kernel: AES CTR mode by8 optimization enabled Feb 13 19:36:26.734031 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Feb 13 19:36:26.705881 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Feb 13 19:36:26.735567 kernel: libata version 3.00 loaded. Feb 13 19:36:26.717545 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Feb 13 19:36:26.720677 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Feb 13 19:36:26.720802 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Feb 13 19:36:26.723514 systemd[1]: Stopping dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Feb 13 19:36:26.724638 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Feb 13 19:36:26.749001 kernel: ahci 0000:00:1f.2: version 3.0 Feb 13 19:36:26.776822 kernel: ACPI: \_SB_.GSIA: Enabled at IRQ 16 Feb 13 19:36:26.776859 kernel: ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode Feb 13 19:36:26.777016 kernel: ahci 0000:00:1f.2: flags: 64bit ncq only Feb 13 19:36:26.777156 kernel: BTRFS: device label OEM devid 1 transid 14 /dev/vda6 scanned by (udev-worker) (478) Feb 13 19:36:26.777174 kernel: scsi host0: ahci Feb 13 19:36:26.777343 kernel: BTRFS: device fsid e9c87d9f-3864-4b45-9be4-80a5397f1fc6 devid 1 transid 38 /dev/vda3 scanned by (udev-worker) (465) Feb 13 19:36:26.777355 kernel: scsi host1: ahci Feb 13 19:36:26.777505 kernel: scsi host2: ahci Feb 13 19:36:26.777651 kernel: scsi host3: ahci Feb 13 19:36:26.777824 kernel: scsi host4: ahci Feb 13 19:36:26.777984 kernel: scsi host5: ahci Feb 13 19:36:26.778131 kernel: ata1: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4100 irq 34 Feb 13 19:36:26.778142 kernel: ata2: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4180 irq 34 Feb 13 19:36:26.778152 kernel: ata3: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4200 irq 34 Feb 13 19:36:26.778162 kernel: ata4: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4280 irq 34 Feb 13 19:36:26.778172 kernel: ata5: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4300 irq 34 Feb 13 19:36:26.778182 kernel: ata6: SATA max UDMA/133 abar m4096@0xfebd4000 port 0xfebd4380 irq 34 Feb 13 19:36:26.724767 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Feb 13 19:36:26.726181 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Feb 13 19:36:26.736333 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Feb 13 19:36:26.776760 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Feb 13 19:36:26.804831 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Feb 13 19:36:26.815560 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Feb 13 19:36:26.820096 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Feb 13 19:36:26.824977 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132. Feb 13 19:36:26.826220 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Feb 13 19:36:26.844920 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Feb 13 19:36:26.848035 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Feb 13 19:36:26.856747 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Feb 13 19:36:26.861736 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Feb 13 19:36:26.865000 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Feb 13 19:36:27.083759 kernel: ata1: SATA link down (SStatus 0 SControl 300) Feb 13 19:36:27.083840 kernel: ata5: SATA link down (SStatus 0 SControl 300) Feb 13 19:36:27.084745 kernel: ata6: SATA link down (SStatus 0 SControl 300) Feb 13 19:36:27.084801 kernel: ata2: SATA link down (SStatus 0 SControl 300) Feb 13 19:36:27.085742 kernel: ata4: SATA link down (SStatus 0 SControl 300) Feb 13 19:36:27.086741 kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Feb 13 19:36:27.088044 kernel: ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 Feb 13 19:36:27.088086 kernel: ata3.00: applying bridge limits Feb 13 19:36:27.088096 kernel: ata3.00: configured for UDMA/100 Feb 13 19:36:27.090747 kernel: scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 Feb 13 19:36:27.128746 kernel: sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Feb 13 19:36:27.146373 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Feb 13 19:36:27.146388 kernel: sr 2:0:0:0: Attached scsi CD-ROM sr0 Feb 13 19:36:27.866742 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Feb 13 19:36:27.867333 disk-uuid[570]: The operation has completed successfully. Feb 13 19:36:27.892723 systemd[1]: disk-uuid.service: Deactivated successfully. Feb 13 19:36:27.892850 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Feb 13 19:36:27.913961 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... Feb 13 19:36:27.917463 sh[593]: Success Feb 13 19:36:27.929739 kernel: device-mapper: verity: sha256 using implementation "sha256-ni" Feb 13 19:36:27.961647 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. Feb 13 19:36:27.971099 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... Feb 13 19:36:27.974038 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. Feb 13 19:36:27.983769 kernel: BTRFS info (device dm-0): first mount of filesystem e9c87d9f-3864-4b45-9be4-80a5397f1fc6 Feb 13 19:36:27.983794 kernel: BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm Feb 13 19:36:27.983804 kernel: BTRFS warning (device dm-0): 'nologreplay' is deprecated, use 'rescue=nologreplay' instead Feb 13 19:36:27.984791 kernel: BTRFS info (device dm-0): disabling log replay at mount time Feb 13 19:36:27.986147 kernel: BTRFS info (device dm-0): using free space tree Feb 13 19:36:27.990201 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. Feb 13 19:36:27.990979 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Feb 13 19:36:28.004853 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Feb 13 19:36:28.005640 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Feb 13 19:36:28.020037 kernel: BTRFS info (device vda6): first mount of filesystem 84d576e4-038f-4c76-aa8e-6cfd81e812ea Feb 13 19:36:28.020066 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Feb 13 19:36:28.020077 kernel: BTRFS info (device vda6): using free space tree Feb 13 19:36:28.024785 kernel: BTRFS info (device vda6): auto enabling async discard Feb 13 19:36:28.032454 systemd[1]: mnt-oem.mount: Deactivated successfully. Feb 13 19:36:28.034073 kernel: BTRFS info (device vda6): last unmount of filesystem 84d576e4-038f-4c76-aa8e-6cfd81e812ea Feb 13 19:36:28.043561 systemd[1]: Finished ignition-setup.service - Ignition (setup). Feb 13 19:36:28.049869 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Feb 13 19:36:28.102073 ignition[694]: Ignition 2.20.0 Feb 13 19:36:28.102086 ignition[694]: Stage: fetch-offline Feb 13 19:36:28.102134 ignition[694]: no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:28.102148 ignition[694]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:28.102278 ignition[694]: parsed url from cmdline: "" Feb 13 19:36:28.102283 ignition[694]: no config URL provided Feb 13 19:36:28.102289 ignition[694]: reading system config file "/usr/lib/ignition/user.ign" Feb 13 19:36:28.102301 ignition[694]: no config at "/usr/lib/ignition/user.ign" Feb 13 19:36:28.102333 ignition[694]: op(1): [started] loading QEMU firmware config module Feb 13 19:36:28.102339 ignition[694]: op(1): executing: "modprobe" "qemu_fw_cfg" Feb 13 19:36:28.115497 ignition[694]: op(1): [finished] loading QEMU firmware config module Feb 13 19:36:28.115768 ignition[694]: parsing config with SHA512: a5dff4c3ca0916e0a56f1a47d9820bf5bc02a06a5fabb9c85e77a58d71288d46c6df92df72cd3252620e0264ab6114319ffa2b268d39b5db33b74037b6503d62 Feb 13 19:36:28.122229 unknown[694]: fetched base config from "system" Feb 13 19:36:28.122252 unknown[694]: fetched user config from "qemu" Feb 13 19:36:28.123218 ignition[694]: fetch-offline: fetch-offline passed Feb 13 19:36:28.124780 ignition[694]: Ignition finished successfully Feb 13 19:36:28.126948 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Feb 13 19:36:28.128401 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Feb 13 19:36:28.138846 systemd[1]: Starting systemd-networkd.service - Network Configuration... Feb 13 19:36:28.159966 systemd-networkd[783]: lo: Link UP Feb 13 19:36:28.159977 systemd-networkd[783]: lo: Gained carrier Feb 13 19:36:28.161556 systemd-networkd[783]: Enumeration completed Feb 13 19:36:28.161628 systemd[1]: Started systemd-networkd.service - Network Configuration. Feb 13 19:36:28.161946 systemd-networkd[783]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Feb 13 19:36:28.161950 systemd-networkd[783]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Feb 13 19:36:28.162671 systemd-networkd[783]: eth0: Link UP Feb 13 19:36:28.162674 systemd-networkd[783]: eth0: Gained carrier Feb 13 19:36:28.162681 systemd-networkd[783]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Feb 13 19:36:28.163885 systemd[1]: Reached target network.target - Network. Feb 13 19:36:28.165687 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Feb 13 19:36:28.175824 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Feb 13 19:36:28.186779 systemd-networkd[783]: eth0: DHCPv4 address 10.0.0.57/16, gateway 10.0.0.1 acquired from 10.0.0.1 Feb 13 19:36:28.188531 ignition[785]: Ignition 2.20.0 Feb 13 19:36:28.188542 ignition[785]: Stage: kargs Feb 13 19:36:28.188698 ignition[785]: no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:28.188709 ignition[785]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:28.189304 ignition[785]: kargs: kargs passed Feb 13 19:36:28.192792 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Feb 13 19:36:28.189339 ignition[785]: Ignition finished successfully Feb 13 19:36:28.202841 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Feb 13 19:36:28.215684 ignition[795]: Ignition 2.20.0 Feb 13 19:36:28.215698 ignition[795]: Stage: disks Feb 13 19:36:28.215888 ignition[795]: no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:28.215899 ignition[795]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:28.218770 systemd[1]: Finished ignition-disks.service - Ignition (disks). Feb 13 19:36:28.216444 ignition[795]: disks: disks passed Feb 13 19:36:28.220552 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Feb 13 19:36:28.216484 ignition[795]: Ignition finished successfully Feb 13 19:36:28.222452 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Feb 13 19:36:28.224320 systemd[1]: Reached target local-fs.target - Local File Systems. Feb 13 19:36:28.224380 systemd[1]: Reached target sysinit.target - System Initialization. Feb 13 19:36:28.224725 systemd[1]: Reached target basic.target - Basic System. Feb 13 19:36:28.241920 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Feb 13 19:36:28.253567 systemd-fsck[806]: ROOT: clean, 14/553520 files, 52654/553472 blocks Feb 13 19:36:28.259791 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Feb 13 19:36:28.268874 systemd[1]: Mounting sysroot.mount - /sysroot... Feb 13 19:36:28.352731 kernel: EXT4-fs (vda9): mounted filesystem c5993b0e-9201-4b44-aa01-79dc9d6c9fc9 r/w with ordered data mode. Quota mode: none. Feb 13 19:36:28.352937 systemd[1]: Mounted sysroot.mount - /sysroot. Feb 13 19:36:28.355068 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Feb 13 19:36:28.368787 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Feb 13 19:36:28.370601 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Feb 13 19:36:28.372893 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Feb 13 19:36:28.372941 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Feb 13 19:36:28.379100 kernel: BTRFS: device label OEM devid 1 transid 15 /dev/vda6 scanned by mount (814) Feb 13 19:36:28.372963 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Feb 13 19:36:28.382775 kernel: BTRFS info (device vda6): first mount of filesystem 84d576e4-038f-4c76-aa8e-6cfd81e812ea Feb 13 19:36:28.382790 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Feb 13 19:36:28.382800 kernel: BTRFS info (device vda6): using free space tree Feb 13 19:36:28.384730 kernel: BTRFS info (device vda6): auto enabling async discard Feb 13 19:36:28.386031 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Feb 13 19:36:28.403632 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Feb 13 19:36:28.406055 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Feb 13 19:36:28.444527 initrd-setup-root[838]: cut: /sysroot/etc/passwd: No such file or directory Feb 13 19:36:28.449922 initrd-setup-root[845]: cut: /sysroot/etc/group: No such file or directory Feb 13 19:36:28.454756 initrd-setup-root[852]: cut: /sysroot/etc/shadow: No such file or directory Feb 13 19:36:28.459259 initrd-setup-root[859]: cut: /sysroot/etc/gshadow: No such file or directory Feb 13 19:36:28.540564 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Feb 13 19:36:28.558848 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Feb 13 19:36:28.559624 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Feb 13 19:36:28.569759 kernel: BTRFS info (device vda6): last unmount of filesystem 84d576e4-038f-4c76-aa8e-6cfd81e812ea Feb 13 19:36:28.583167 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Feb 13 19:36:28.593709 ignition[928]: INFO : Ignition 2.20.0 Feb 13 19:36:28.593709 ignition[928]: INFO : Stage: mount Feb 13 19:36:28.595393 ignition[928]: INFO : no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:28.595393 ignition[928]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:28.595393 ignition[928]: INFO : mount: mount passed Feb 13 19:36:28.595393 ignition[928]: INFO : Ignition finished successfully Feb 13 19:36:28.600946 systemd[1]: Finished ignition-mount.service - Ignition (mount). Feb 13 19:36:28.616782 systemd[1]: Starting ignition-files.service - Ignition (files)... Feb 13 19:36:28.983667 systemd[1]: sysroot-oem.mount: Deactivated successfully. Feb 13 19:36:28.995910 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Feb 13 19:36:29.004559 kernel: BTRFS: device label OEM devid 1 transid 16 /dev/vda6 scanned by mount (941) Feb 13 19:36:29.004597 kernel: BTRFS info (device vda6): first mount of filesystem 84d576e4-038f-4c76-aa8e-6cfd81e812ea Feb 13 19:36:29.004621 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Feb 13 19:36:29.006062 kernel: BTRFS info (device vda6): using free space tree Feb 13 19:36:29.008742 kernel: BTRFS info (device vda6): auto enabling async discard Feb 13 19:36:29.010698 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Feb 13 19:36:29.036892 ignition[958]: INFO : Ignition 2.20.0 Feb 13 19:36:29.036892 ignition[958]: INFO : Stage: files Feb 13 19:36:29.038805 ignition[958]: INFO : no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:29.038805 ignition[958]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:29.038805 ignition[958]: DEBUG : files: compiled without relabeling support, skipping Feb 13 19:36:29.038805 ignition[958]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Feb 13 19:36:29.038805 ignition[958]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Feb 13 19:36:29.045174 ignition[958]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Feb 13 19:36:29.045174 ignition[958]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Feb 13 19:36:29.045174 ignition[958]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Feb 13 19:36:29.045174 ignition[958]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/etc/flatcar/update.conf" Feb 13 19:36:29.045174 ignition[958]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/etc/flatcar/update.conf" Feb 13 19:36:29.043037 unknown[958]: wrote ssh authorized keys file for user: core Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(4): [started] processing unit "etcd-member.service" Feb 13 19:36:29.053846 ignition[958]: 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" Feb 13 19:36:29.053846 ignition[958]: 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" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(4): [finished] processing unit "etcd-member.service" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(6): [started] processing unit "coreos-metadata.service" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(6): op(7): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(6): op(7): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(6): [finished] processing unit "coreos-metadata.service" Feb 13 19:36:29.053846 ignition[958]: INFO : files: op(8): [started] setting preset to disabled for "coreos-metadata.service" Feb 13 19:36:29.089253 ignition[958]: INFO : files: op(8): op(9): [started] removing enablement symlink(s) for "coreos-metadata.service" Feb 13 19:36:29.094750 ignition[958]: INFO : files: op(8): op(9): [finished] removing enablement symlink(s) for "coreos-metadata.service" Feb 13 19:36:29.096393 ignition[958]: INFO : files: op(8): [finished] setting preset to disabled for "coreos-metadata.service" Feb 13 19:36:29.096393 ignition[958]: INFO : files: op(a): [started] setting preset to enabled for "etcd-member.service" Feb 13 19:36:29.096393 ignition[958]: INFO : files: op(a): [finished] setting preset to enabled for "etcd-member.service" Feb 13 19:36:29.096393 ignition[958]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Feb 13 19:36:29.096393 ignition[958]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Feb 13 19:36:29.096393 ignition[958]: INFO : files: files passed Feb 13 19:36:29.096393 ignition[958]: INFO : Ignition finished successfully Feb 13 19:36:29.097987 systemd[1]: Finished ignition-files.service - Ignition (files). Feb 13 19:36:29.106937 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Feb 13 19:36:29.109363 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Feb 13 19:36:29.111260 systemd[1]: ignition-quench.service: Deactivated successfully. Feb 13 19:36:29.111391 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Feb 13 19:36:29.119828 initrd-setup-root-after-ignition[986]: grep: /sysroot/oem/oem-release: No such file or directory Feb 13 19:36:29.122564 initrd-setup-root-after-ignition[988]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Feb 13 19:36:29.122564 initrd-setup-root-after-ignition[988]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Feb 13 19:36:29.125816 initrd-setup-root-after-ignition[992]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Feb 13 19:36:29.125499 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Feb 13 19:36:29.127617 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Feb 13 19:36:29.137867 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Feb 13 19:36:29.162164 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Feb 13 19:36:29.162297 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Feb 13 19:36:29.164673 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Feb 13 19:36:29.166793 systemd[1]: Reached target initrd.target - Initrd Default Target. Feb 13 19:36:29.167925 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Feb 13 19:36:29.168688 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Feb 13 19:36:29.187356 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Feb 13 19:36:29.190247 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Feb 13 19:36:29.205287 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Feb 13 19:36:29.206769 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Feb 13 19:36:29.209194 systemd[1]: Stopped target timers.target - Timer Units. Feb 13 19:36:29.211469 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Feb 13 19:36:29.211627 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Feb 13 19:36:29.214289 systemd[1]: Stopped target initrd.target - Initrd Default Target. Feb 13 19:36:29.216040 systemd[1]: Stopped target basic.target - Basic System. Feb 13 19:36:29.218304 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Feb 13 19:36:29.220615 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Feb 13 19:36:29.222956 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Feb 13 19:36:29.225087 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Feb 13 19:36:29.227198 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Feb 13 19:36:29.229486 systemd[1]: Stopped target sysinit.target - System Initialization. Feb 13 19:36:29.231473 systemd[1]: Stopped target local-fs.target - Local File Systems. Feb 13 19:36:29.233934 systemd[1]: Stopped target swap.target - Swaps. Feb 13 19:36:29.235623 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Feb 13 19:36:29.235750 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Feb 13 19:36:29.238045 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Feb 13 19:36:29.239793 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Feb 13 19:36:29.241759 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Feb 13 19:36:29.241904 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Feb 13 19:36:29.243977 systemd[1]: dracut-initqueue.service: Deactivated successfully. Feb 13 19:36:29.244121 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Feb 13 19:36:29.246481 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Feb 13 19:36:29.246614 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Feb 13 19:36:29.248488 systemd[1]: Stopped target paths.target - Path Units. Feb 13 19:36:29.250165 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Feb 13 19:36:29.253785 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Feb 13 19:36:29.255938 systemd[1]: Stopped target slices.target - Slice Units. Feb 13 19:36:29.258129 systemd[1]: Stopped target sockets.target - Socket Units. Feb 13 19:36:29.260136 systemd[1]: iscsid.socket: Deactivated successfully. Feb 13 19:36:29.260273 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Feb 13 19:36:29.262455 systemd[1]: iscsiuio.socket: Deactivated successfully. Feb 13 19:36:29.262578 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Feb 13 19:36:29.265190 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Feb 13 19:36:29.265522 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Feb 13 19:36:29.267434 systemd[1]: ignition-files.service: Deactivated successfully. Feb 13 19:36:29.267549 systemd[1]: Stopped ignition-files.service - Ignition (files). Feb 13 19:36:29.283864 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Feb 13 19:36:29.285547 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Feb 13 19:36:29.286660 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Feb 13 19:36:29.286788 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Feb 13 19:36:29.288934 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Feb 13 19:36:29.289137 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Feb 13 19:36:29.295230 systemd[1]: initrd-cleanup.service: Deactivated successfully. Feb 13 19:36:29.295355 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Feb 13 19:36:29.299519 ignition[1013]: INFO : Ignition 2.20.0 Feb 13 19:36:29.299519 ignition[1013]: INFO : Stage: umount Feb 13 19:36:29.301241 ignition[1013]: INFO : no configs at "/usr/lib/ignition/base.d" Feb 13 19:36:29.301241 ignition[1013]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Feb 13 19:36:29.303876 ignition[1013]: INFO : umount: umount passed Feb 13 19:36:29.303876 ignition[1013]: INFO : Ignition finished successfully Feb 13 19:36:29.307205 systemd[1]: ignition-mount.service: Deactivated successfully. Feb 13 19:36:29.308292 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Feb 13 19:36:29.310542 systemd[1]: Stopped target network.target - Network. Feb 13 19:36:29.311529 systemd[1]: ignition-disks.service: Deactivated successfully. Feb 13 19:36:29.318945 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Feb 13 19:36:29.320942 systemd[1]: ignition-kargs.service: Deactivated successfully. Feb 13 19:36:29.321871 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Feb 13 19:36:29.323818 systemd[1]: ignition-setup.service: Deactivated successfully. Feb 13 19:36:29.323868 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Feb 13 19:36:29.326694 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Feb 13 19:36:29.327682 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Feb 13 19:36:29.329920 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Feb 13 19:36:29.332166 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Feb 13 19:36:29.335309 systemd[1]: sysroot-boot.mount: Deactivated successfully. Feb 13 19:36:29.336751 systemd-networkd[783]: eth0: DHCPv6 lease lost Feb 13 19:36:29.336816 systemd[1]: sysroot-boot.service: Deactivated successfully. Feb 13 19:36:29.336937 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Feb 13 19:36:29.340744 systemd[1]: systemd-networkd.service: Deactivated successfully. Feb 13 19:36:29.341767 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Feb 13 19:36:29.344222 systemd[1]: systemd-resolved.service: Deactivated successfully. Feb 13 19:36:29.345242 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Feb 13 19:36:29.349824 systemd[1]: systemd-networkd.socket: Deactivated successfully. Feb 13 19:36:29.349875 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Feb 13 19:36:29.352945 systemd[1]: initrd-setup-root.service: Deactivated successfully. Feb 13 19:36:29.353003 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Feb 13 19:36:29.365849 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Feb 13 19:36:29.365926 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Feb 13 19:36:29.365988 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Feb 13 19:36:29.370792 systemd[1]: systemd-sysctl.service: Deactivated successfully. Feb 13 19:36:29.370857 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Feb 13 19:36:29.373830 systemd[1]: systemd-modules-load.service: Deactivated successfully. Feb 13 19:36:29.374961 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Feb 13 19:36:29.379798 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Feb 13 19:36:29.381039 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Feb 13 19:36:29.384120 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Feb 13 19:36:29.399506 systemd[1]: network-cleanup.service: Deactivated successfully. Feb 13 19:36:29.399662 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Feb 13 19:36:29.401886 systemd[1]: systemd-udevd.service: Deactivated successfully. Feb 13 19:36:29.402053 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Feb 13 19:36:29.404733 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Feb 13 19:36:29.404809 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Feb 13 19:36:29.405968 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Feb 13 19:36:29.406013 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Feb 13 19:36:29.406279 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Feb 13 19:36:29.406326 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Feb 13 19:36:29.407083 systemd[1]: dracut-cmdline.service: Deactivated successfully. Feb 13 19:36:29.407131 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Feb 13 19:36:29.414070 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Feb 13 19:36:29.414120 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Feb 13 19:36:29.418030 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Feb 13 19:36:29.419219 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Feb 13 19:36:29.419273 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Feb 13 19:36:29.421495 systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. Feb 13 19:36:29.421542 systemd[1]: Stopped systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Feb 13 19:36:29.422815 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Feb 13 19:36:29.422862 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Feb 13 19:36:29.423332 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Feb 13 19:36:29.423376 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Feb 13 19:36:29.432159 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Feb 13 19:36:29.432285 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Feb 13 19:36:29.434421 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Feb 13 19:36:29.445842 systemd[1]: Starting initrd-switch-root.service - Switch Root... Feb 13 19:36:29.453184 systemd[1]: Switching root. Feb 13 19:36:29.487455 systemd-journald[194]: Journal stopped Feb 13 19:36:30.272069 systemd-journald[194]: Received SIGTERM from PID 1 (systemd). Feb 13 19:36:30.272129 kernel: SELinux: policy capability network_peer_controls=1 Feb 13 19:36:30.272149 kernel: SELinux: policy capability open_perms=1 Feb 13 19:36:30.272161 kernel: SELinux: policy capability extended_socket_class=1 Feb 13 19:36:30.272179 kernel: SELinux: policy capability always_check_network=0 Feb 13 19:36:30.272197 kernel: SELinux: policy capability cgroup_seclabel=1 Feb 13 19:36:30.272209 kernel: SELinux: policy capability nnp_nosuid_transition=1 Feb 13 19:36:30.272225 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Feb 13 19:36:30.272236 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Feb 13 19:36:30.272249 kernel: audit: type=1403 audit(1739475389.568:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Feb 13 19:36:30.272261 systemd[1]: Successfully loaded SELinux policy in 38.277ms. Feb 13 19:36:30.272285 systemd[1]: Relabeled /dev, /dev/shm, /run, /sys/fs/cgroup in 12.496ms. Feb 13 19:36:30.272299 systemd[1]: systemd 255 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL -ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified) Feb 13 19:36:30.272311 systemd[1]: Detected virtualization kvm. Feb 13 19:36:30.272323 systemd[1]: Detected architecture x86-64. Feb 13 19:36:30.272335 systemd[1]: Detected first boot. Feb 13 19:36:30.272347 systemd[1]: Initializing machine ID from VM UUID. Feb 13 19:36:30.272359 zram_generator::config[1058]: No configuration found. Feb 13 19:36:30.272372 systemd[1]: Populated /etc with preset unit settings. Feb 13 19:36:30.272387 systemd[1]: initrd-switch-root.service: Deactivated successfully. Feb 13 19:36:30.272399 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Feb 13 19:36:30.272411 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Feb 13 19:36:30.272428 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Feb 13 19:36:30.272441 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Feb 13 19:36:30.272453 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Feb 13 19:36:30.272469 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Feb 13 19:36:30.272481 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Feb 13 19:36:30.272493 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Feb 13 19:36:30.272505 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Feb 13 19:36:30.272518 systemd[1]: Created slice user.slice - User and Session Slice. Feb 13 19:36:30.272530 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Feb 13 19:36:30.272542 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Feb 13 19:36:30.272554 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Feb 13 19:36:30.272569 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Feb 13 19:36:30.272581 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Feb 13 19:36:30.272593 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Feb 13 19:36:30.272605 systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0... Feb 13 19:36:30.272617 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Feb 13 19:36:30.272629 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Feb 13 19:36:30.272641 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Feb 13 19:36:30.272653 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Feb 13 19:36:30.272667 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Feb 13 19:36:30.272679 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Feb 13 19:36:30.272691 systemd[1]: Reached target remote-fs.target - Remote File Systems. Feb 13 19:36:30.272703 systemd[1]: Reached target slices.target - Slice Units. Feb 13 19:36:30.272729 systemd[1]: Reached target swap.target - Swaps. Feb 13 19:36:30.272744 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Feb 13 19:36:30.272756 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Feb 13 19:36:30.272768 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Feb 13 19:36:30.272780 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Feb 13 19:36:30.272795 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Feb 13 19:36:30.272808 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Feb 13 19:36:30.272820 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Feb 13 19:36:30.272831 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Feb 13 19:36:30.272843 systemd[1]: Mounting media.mount - External Media Directory... Feb 13 19:36:30.272856 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.272868 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Feb 13 19:36:30.272880 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Feb 13 19:36:30.272892 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Feb 13 19:36:30.272907 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). Feb 13 19:36:30.272919 systemd[1]: Reached target machines.target - Containers. Feb 13 19:36:30.272931 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Feb 13 19:36:30.272943 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Feb 13 19:36:30.272955 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Feb 13 19:36:30.272967 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Feb 13 19:36:30.272979 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Feb 13 19:36:30.272991 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Feb 13 19:36:30.273007 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Feb 13 19:36:30.273024 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Feb 13 19:36:30.273036 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Feb 13 19:36:30.273048 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Feb 13 19:36:30.273059 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Feb 13 19:36:30.273071 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Feb 13 19:36:30.273083 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Feb 13 19:36:30.273094 systemd[1]: Stopped systemd-fsck-usr.service. Feb 13 19:36:30.273108 kernel: fuse: init (API version 7.39) Feb 13 19:36:30.273119 kernel: loop: module loaded Feb 13 19:36:30.273131 systemd[1]: Starting systemd-journald.service - Journal Service... Feb 13 19:36:30.273143 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Feb 13 19:36:30.273156 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Feb 13 19:36:30.273167 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Feb 13 19:36:30.273192 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Feb 13 19:36:30.273225 systemd-journald[1135]: Collecting audit messages is disabled. Feb 13 19:36:30.273250 systemd[1]: verity-setup.service: Deactivated successfully. Feb 13 19:36:30.273262 systemd[1]: Stopped verity-setup.service. Feb 13 19:36:30.273274 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.273286 systemd-journald[1135]: Journal started Feb 13 19:36:30.273307 systemd-journald[1135]: Runtime Journal (/run/log/journal/428f8b7b87cd429097bd2d52a56c643c) is 6.0M, max 48.4M, 42.3M free. Feb 13 19:36:30.060202 systemd[1]: Queued start job for default target multi-user.target. Feb 13 19:36:30.076564 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Feb 13 19:36:30.077017 systemd[1]: systemd-journald.service: Deactivated successfully. Feb 13 19:36:30.277740 kernel: ACPI: bus type drm_connector registered Feb 13 19:36:30.277803 systemd[1]: Started systemd-journald.service - Journal Service. Feb 13 19:36:30.280118 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Feb 13 19:36:30.281308 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Feb 13 19:36:30.282541 systemd[1]: Mounted media.mount - External Media Directory. Feb 13 19:36:30.283777 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Feb 13 19:36:30.285228 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Feb 13 19:36:30.286491 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Feb 13 19:36:30.287788 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Feb 13 19:36:30.289262 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Feb 13 19:36:30.290824 systemd[1]: modprobe@configfs.service: Deactivated successfully. Feb 13 19:36:30.290999 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Feb 13 19:36:30.292496 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Feb 13 19:36:30.292661 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Feb 13 19:36:30.294160 systemd[1]: modprobe@drm.service: Deactivated successfully. Feb 13 19:36:30.294336 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Feb 13 19:36:30.295749 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Feb 13 19:36:30.295914 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Feb 13 19:36:30.297618 systemd[1]: modprobe@fuse.service: Deactivated successfully. Feb 13 19:36:30.297800 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Feb 13 19:36:30.299200 systemd[1]: modprobe@loop.service: Deactivated successfully. Feb 13 19:36:30.299365 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Feb 13 19:36:30.300775 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Feb 13 19:36:30.302395 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Feb 13 19:36:30.303943 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Feb 13 19:36:30.317275 systemd[1]: Reached target network-pre.target - Preparation for Network. Feb 13 19:36:30.323934 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Feb 13 19:36:30.326196 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Feb 13 19:36:30.327320 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Feb 13 19:36:30.327346 systemd[1]: Reached target local-fs.target - Local File Systems. Feb 13 19:36:30.329299 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management (Varlink). Feb 13 19:36:30.332669 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Feb 13 19:36:30.335047 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Feb 13 19:36:30.336285 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Feb 13 19:36:30.337697 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Feb 13 19:36:30.341054 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Feb 13 19:36:30.342271 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Feb 13 19:36:30.346866 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Feb 13 19:36:30.348945 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Feb 13 19:36:30.353830 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Feb 13 19:36:30.359423 systemd-journald[1135]: Time spent on flushing to /var/log/journal/428f8b7b87cd429097bd2d52a56c643c is 20.016ms for 923 entries. Feb 13 19:36:30.359423 systemd-journald[1135]: System Journal (/var/log/journal/428f8b7b87cd429097bd2d52a56c643c) is 8.0M, max 195.6M, 187.6M free. Feb 13 19:36:30.388413 systemd-journald[1135]: Received client request to flush runtime journal. Feb 13 19:36:30.366604 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Feb 13 19:36:30.368969 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Feb 13 19:36:30.371826 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Feb 13 19:36:30.373511 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Feb 13 19:36:30.391982 kernel: loop0: detected capacity change from 0 to 138184 Feb 13 19:36:30.375163 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Feb 13 19:36:30.377559 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Feb 13 19:36:30.385055 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Feb 13 19:36:30.392262 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Feb 13 19:36:30.396907 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Feb 13 19:36:30.406970 systemd[1]: Starting systemd-machine-id-commit.service - Commit a transient machine-id on disk... Feb 13 19:36:30.411876 systemd[1]: Starting systemd-udev-settle.service - Wait for udev To Complete Device Initialization... Feb 13 19:36:30.413682 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Feb 13 19:36:30.419776 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Feb 13 19:36:30.424088 systemd-tmpfiles[1173]: ACLs are not supported, ignoring. Feb 13 19:36:30.424105 systemd-tmpfiles[1173]: ACLs are not supported, ignoring. Feb 13 19:36:30.427701 udevadm[1187]: systemd-udev-settle.service is deprecated. Please fix lvm2-activation.service, lvm2-activation-early.service not to pull it in. Feb 13 19:36:30.430807 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Feb 13 19:36:30.440913 systemd[1]: Starting systemd-sysusers.service - Create System Users... Feb 13 19:36:30.442893 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Feb 13 19:36:30.443891 systemd[1]: Finished systemd-machine-id-commit.service - Commit a transient machine-id on disk. Feb 13 19:36:30.449728 kernel: loop1: detected capacity change from 0 to 140992 Feb 13 19:36:30.480163 systemd[1]: Finished systemd-sysusers.service - Create System Users. Feb 13 19:36:30.483742 kernel: loop2: detected capacity change from 0 to 138184 Feb 13 19:36:30.493974 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Feb 13 19:36:30.495969 kernel: loop3: detected capacity change from 0 to 140992 Feb 13 19:36:30.507527 (sd-merge)[1195]: Using extensions 'containerd-flatcar', 'docker-flatcar'. Feb 13 19:36:30.508041 (sd-merge)[1195]: Merged extensions into '/usr'. Feb 13 19:36:30.512792 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Feb 13 19:36:30.515830 systemd-tmpfiles[1197]: ACLs are not supported, ignoring. Feb 13 19:36:30.515848 systemd-tmpfiles[1197]: ACLs are not supported, ignoring. Feb 13 19:36:30.525890 systemd[1]: Starting ensure-sysext.service... Feb 13 19:36:30.530053 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Feb 13 19:36:30.531786 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Feb 13 19:36:30.537527 systemd[1]: Reloading requested from client PID 1200 ('systemctl') (unit ensure-sysext.service)... Feb 13 19:36:30.537537 systemd[1]: Reloading... Feb 13 19:36:30.559322 systemd-tmpfiles[1201]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Feb 13 19:36:30.559627 systemd-tmpfiles[1201]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Feb 13 19:36:30.561912 systemd-tmpfiles[1201]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Feb 13 19:36:30.562196 systemd-tmpfiles[1201]: ACLs are not supported, ignoring. Feb 13 19:36:30.562276 systemd-tmpfiles[1201]: ACLs are not supported, ignoring. Feb 13 19:36:30.565980 systemd-tmpfiles[1201]: Detected autofs mount point /boot during canonicalization of boot. Feb 13 19:36:30.565993 systemd-tmpfiles[1201]: Skipping /boot Feb 13 19:36:30.580983 systemd-tmpfiles[1201]: Detected autofs mount point /boot during canonicalization of boot. Feb 13 19:36:30.581081 systemd-tmpfiles[1201]: Skipping /boot Feb 13 19:36:30.595749 zram_generator::config[1227]: No configuration found. Feb 13 19:36:30.686246 ldconfig[1167]: /sbin/ldconfig: /usr/lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Feb 13 19:36:30.728403 systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, updating /var/run/docker.sock → /run/docker.sock; please update the unit file accordingly. Feb 13 19:36:30.781119 systemd[1]: Reloading finished in 243 ms. Feb 13 19:36:30.811648 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Feb 13 19:36:30.821286 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Feb 13 19:36:30.829984 systemd[1]: Starting audit-rules.service - Load Audit Rules... Feb 13 19:36:30.832483 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Feb 13 19:36:30.835451 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Feb 13 19:36:30.841780 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Feb 13 19:36:30.844921 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Feb 13 19:36:30.848575 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.848791 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Feb 13 19:36:30.849877 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Feb 13 19:36:30.855933 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Feb 13 19:36:30.859942 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Feb 13 19:36:30.861125 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Feb 13 19:36:30.866093 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Feb 13 19:36:30.867424 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.869036 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Feb 13 19:36:30.870242 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Feb 13 19:36:30.889545 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Feb 13 19:36:30.889898 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Feb 13 19:36:30.892034 systemd[1]: modprobe@loop.service: Deactivated successfully. Feb 13 19:36:30.892309 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Feb 13 19:36:30.899270 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Feb 13 19:36:30.899456 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Feb 13 19:36:30.901107 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Feb 13 19:36:30.903349 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Feb 13 19:36:30.908882 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.909127 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Feb 13 19:36:30.910589 augenrules[1300]: No rules Feb 13 19:36:30.915959 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Feb 13 19:36:30.918331 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Feb 13 19:36:30.920566 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Feb 13 19:36:30.921689 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Feb 13 19:36:30.921839 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.922684 systemd[1]: audit-rules.service: Deactivated successfully. Feb 13 19:36:30.922921 systemd[1]: Finished audit-rules.service - Load Audit Rules. Feb 13 19:36:30.924544 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Feb 13 19:36:30.924728 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Feb 13 19:36:30.930219 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Feb 13 19:36:30.930388 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Feb 13 19:36:30.932083 systemd[1]: modprobe@loop.service: Deactivated successfully. Feb 13 19:36:30.932257 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Feb 13 19:36:30.935548 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.945090 systemd[1]: Starting audit-rules.service - Load Audit Rules... Feb 13 19:36:30.946126 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Feb 13 19:36:30.947250 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Feb 13 19:36:30.949930 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Feb 13 19:36:30.952730 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Feb 13 19:36:30.952868 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Feb 13 19:36:30.952973 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Feb 13 19:36:30.956666 systemd[1]: Finished ensure-sysext.service. Feb 13 19:36:30.958074 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Feb 13 19:36:30.958421 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Feb 13 19:36:30.960289 systemd[1]: modprobe@drm.service: Deactivated successfully. Feb 13 19:36:30.960459 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Feb 13 19:36:30.964891 systemd[1]: Started systemd-userdbd.service - User Database Manager. Feb 13 19:36:30.966531 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Feb 13 19:36:30.972125 augenrules[1313]: /sbin/augenrules: No change Feb 13 19:36:30.975963 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Feb 13 19:36:30.984211 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Feb 13 19:36:30.985790 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). Feb 13 19:36:30.990332 augenrules[1343]: No rules Feb 13 19:36:30.992205 systemd[1]: audit-rules.service: Deactivated successfully. Feb 13 19:36:30.992498 systemd[1]: Finished audit-rules.service - Load Audit Rules. Feb 13 19:36:30.994081 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Feb 13 19:36:31.003916 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Feb 13 19:36:31.008899 systemd[1]: Starting systemd-update-done.service - Update is Completed... Feb 13 19:36:31.021416 systemd[1]: Finished systemd-update-done.service - Update is Completed. Feb 13 19:36:31.031873 systemd-udevd[1350]: Using default interface naming scheme 'v255'. Feb 13 19:36:31.035873 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Feb 13 19:36:31.037434 systemd[1]: Reached target time-set.target - System Time Set. Feb 13 19:36:31.041761 systemd-resolved[1271]: Positive Trust Anchors: Feb 13 19:36:31.041776 systemd-resolved[1271]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Feb 13 19:36:31.041808 systemd-resolved[1271]: 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 Feb 13 19:36:31.045191 systemd-resolved[1271]: Defaulting to hostname 'linux'. Feb 13 19:36:31.046739 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Feb 13 19:36:31.048079 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Feb 13 19:36:31.050435 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Feb 13 19:36:31.061846 systemd[1]: Starting systemd-networkd.service - Network Configuration... Feb 13 19:36:31.086133 systemd[1]: Condition check resulted in dev-ttyS0.device - /dev/ttyS0 being skipped. Feb 13 19:36:31.087827 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1360) Feb 13 19:36:31.126191 systemd-networkd[1358]: lo: Link UP Feb 13 19:36:31.126202 systemd-networkd[1358]: lo: Gained carrier Feb 13 19:36:31.127829 systemd-networkd[1358]: Enumeration completed Feb 13 19:36:31.129265 systemd-networkd[1358]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Feb 13 19:36:31.129348 systemd-networkd[1358]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Feb 13 19:36:31.129387 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Feb 13 19:36:31.130153 systemd-networkd[1358]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Feb 13 19:36:31.130263 systemd-networkd[1358]: eth0: Link UP Feb 13 19:36:31.130270 systemd-networkd[1358]: eth0: Gained carrier Feb 13 19:36:31.130281 systemd-networkd[1358]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Feb 13 19:36:31.131135 systemd[1]: Started systemd-networkd.service - Network Configuration. Feb 13 19:36:31.132481 systemd[1]: Reached target network.target - Network. Feb 13 19:36:31.140144 systemd-networkd[1358]: eth0: DHCPv4 address 10.0.0.57/16, gateway 10.0.0.1 acquired from 10.0.0.1 Feb 13 19:36:31.141452 systemd-timesyncd[1333]: Network configuration changed, trying to establish connection. Feb 13 19:36:31.757032 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input2 Feb 13 19:36:31.141881 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Feb 13 19:36:31.756187 systemd-timesyncd[1333]: Contacted time server 10.0.0.1:123 (10.0.0.1). Feb 13 19:36:31.756230 systemd-timesyncd[1333]: Initial clock synchronization to Thu 2025-02-13 19:36:31.756088 UTC. Feb 13 19:36:31.756277 systemd-resolved[1271]: Clock change detected. Flushing caches. Feb 13 19:36:31.761595 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Feb 13 19:36:31.764693 kernel: ACPI: button: Power Button [PWRF] Feb 13 19:36:31.773256 kernel: i801_smbus 0000:00:1f.3: SMBus using PCI interrupt Feb 13 19:36:31.773560 kernel: i2c i2c-0: 1/1 memory slots populated (from DMI) Feb 13 19:36:31.773745 kernel: i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD Feb 13 19:36:31.776516 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Feb 13 19:36:31.804505 kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3 Feb 13 19:36:31.806779 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Feb 13 19:36:31.815484 kernel: mousedev: PS/2 mouse device common for all mice Feb 13 19:36:31.903497 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Feb 13 19:36:31.909697 kernel: kvm_amd: TSC scaling supported Feb 13 19:36:31.909742 kernel: kvm_amd: Nested Virtualization enabled Feb 13 19:36:31.909756 kernel: kvm_amd: Nested Paging enabled Feb 13 19:36:31.909772 kernel: kvm_amd: LBR virtualization supported Feb 13 19:36:31.910773 kernel: kvm_amd: Virtual VMLOAD VMSAVE supported Feb 13 19:36:31.910791 kernel: kvm_amd: Virtual GIF supported Feb 13 19:36:31.928488 kernel: EDAC MC: Ver: 3.0.0 Feb 13 19:36:31.960803 systemd[1]: Finished systemd-udev-settle.service - Wait for udev To Complete Device Initialization. Feb 13 19:36:31.975618 systemd[1]: Starting lvm2-activation-early.service - Activation of LVM2 logical volumes... Feb 13 19:36:31.984184 lvm[1398]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Feb 13 19:36:32.020612 systemd[1]: Finished lvm2-activation-early.service - Activation of LVM2 logical volumes. Feb 13 19:36:32.022184 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Feb 13 19:36:32.023337 systemd[1]: Reached target sysinit.target - System Initialization. Feb 13 19:36:32.024597 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Feb 13 19:36:32.025888 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Feb 13 19:36:32.027372 systemd[1]: Started logrotate.timer - Daily rotation of log files. Feb 13 19:36:32.028602 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Feb 13 19:36:32.030131 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Feb 13 19:36:32.031605 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Feb 13 19:36:32.031639 systemd[1]: Reached target paths.target - Path Units. Feb 13 19:36:32.032586 systemd[1]: Reached target timers.target - Timer Units. Feb 13 19:36:32.034514 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Feb 13 19:36:32.037428 systemd[1]: Starting docker.socket - Docker Socket for the API... Feb 13 19:36:32.052098 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Feb 13 19:36:32.054521 systemd[1]: Starting lvm2-activation.service - Activation of LVM2 logical volumes... Feb 13 19:36:32.056068 systemd[1]: Listening on docker.socket - Docker Socket for the API. Feb 13 19:36:32.057307 systemd[1]: Reached target sockets.target - Socket Units. Feb 13 19:36:32.058302 systemd[1]: Reached target basic.target - Basic System. Feb 13 19:36:32.059299 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Feb 13 19:36:32.059327 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Feb 13 19:36:32.060345 systemd[1]: Starting containerd.service - containerd container runtime... Feb 13 19:36:32.062508 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Feb 13 19:36:32.067408 lvm[1402]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Feb 13 19:36:32.067552 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Feb 13 19:36:32.070689 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Feb 13 19:36:32.072340 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). Feb 13 19:36:32.073859 jq[1405]: false Feb 13 19:36:32.074700 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Feb 13 19:36:32.079603 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Feb 13 19:36:32.082395 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Feb 13 19:36:32.089027 systemd[1]: Starting systemd-logind.service - User Login Management... Feb 13 19:36:32.092289 extend-filesystems[1406]: Found loop2 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found loop3 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found sr0 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda1 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda2 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda3 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found usr Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda4 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda6 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda7 Feb 13 19:36:32.095260 extend-filesystems[1406]: Found vda9 Feb 13 19:36:32.095260 extend-filesystems[1406]: Checking size of /dev/vda9 Feb 13 19:36:32.093660 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Feb 13 19:36:32.133672 extend-filesystems[1406]: Old size kept for /dev/vda9 Feb 13 19:36:32.140435 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1360) Feb 13 19:36:32.100233 dbus-daemon[1404]: [system] SELinux support is enabled Feb 13 19:36:32.094215 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Feb 13 19:36:32.096213 systemd[1]: Starting update-engine.service - Update Engine... Feb 13 19:36:32.141087 update_engine[1415]: I20250213 19:36:32.122120 1415 main.cc:92] Flatcar Update Engine starting Feb 13 19:36:32.141087 update_engine[1415]: I20250213 19:36:32.123448 1415 update_check_scheduler.cc:74] Next update check in 11m23s Feb 13 19:36:32.099024 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Feb 13 19:36:32.141412 jq[1420]: true Feb 13 19:36:32.103388 systemd[1]: Started dbus.service - D-Bus System Message Bus. Feb 13 19:36:32.106401 systemd[1]: Finished lvm2-activation.service - Activation of LVM2 logical volumes. Feb 13 19:36:32.111354 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Feb 13 19:36:32.147680 jq[1426]: true Feb 13 19:36:32.111586 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Feb 13 19:36:32.111934 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Feb 13 19:36:32.112316 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Feb 13 19:36:32.117506 systemd[1]: motdgen.service: Deactivated successfully. Feb 13 19:36:32.117716 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Feb 13 19:36:32.128212 systemd[1]: extend-filesystems.service: Deactivated successfully. Feb 13 19:36:32.134724 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Feb 13 19:36:32.136735 (ntainerd)[1428]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR Feb 13 19:36:32.167025 systemd-logind[1412]: Watching system buttons on /dev/input/event1 (Power Button) Feb 13 19:36:32.167381 systemd-logind[1412]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) Feb 13 19:36:32.168765 systemd[1]: Started update-engine.service - Update Engine. Feb 13 19:36:32.168867 systemd-logind[1412]: New seat seat0. Feb 13 19:36:32.172535 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). Feb 13 19:36:32.172741 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Feb 13 19:36:32.175716 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). Feb 13 19:36:32.175788 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Feb 13 19:36:32.185705 systemd[1]: Started locksmithd.service - Cluster reboot manager. Feb 13 19:36:32.187235 sshd_keygen[1423]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Feb 13 19:36:32.186987 systemd[1]: Started systemd-logind.service - User Login Management. Feb 13 19:36:32.211754 locksmithd[1450]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Feb 13 19:36:32.212246 bash[1455]: Updated "/home/core/.ssh/authorized_keys" Feb 13 19:36:32.213039 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Feb 13 19:36:32.215946 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Feb 13 19:36:32.218385 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Feb 13 19:36:32.230794 systemd[1]: Starting issuegen.service - Generate /run/issue... Feb 13 19:36:32.237450 systemd[1]: issuegen.service: Deactivated successfully. Feb 13 19:36:32.237817 systemd[1]: Finished issuegen.service - Generate /run/issue. Feb 13 19:36:32.241500 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Feb 13 19:36:32.256210 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Feb 13 19:36:32.272745 systemd[1]: Started getty@tty1.service - Getty on tty1. Feb 13 19:36:32.274934 systemd[1]: Started serial-getty@ttyS0.service - Serial Getty on ttyS0. Feb 13 19:36:32.276193 systemd[1]: Reached target getty.target - Login Prompts. Feb 13 19:36:32.336974 containerd[1428]: time="2025-02-13T19:36:32.336871444Z" level=info msg="starting containerd" revision=9b2ad7760328148397346d10c7b2004271249db4 version=v1.7.23 Feb 13 19:36:32.360323 containerd[1428]: time="2025-02-13T19:36:32.360237425Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.aufs\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362166 containerd[1428]: time="2025-02-13T19:36:32.362114445Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.aufs\"..." error="aufs is not supported (modprobe aufs failed: exit status 1 \"modprobe: FATAL: Module aufs not found in directory /lib/modules/6.6.74-flatcar\\n\"): skip plugin" type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362166 containerd[1428]: time="2025-02-13T19:36:32.362154149Z" level=info msg="loading plugin \"io.containerd.event.v1.exchange\"..." type=io.containerd.event.v1 Feb 13 19:36:32.362244 containerd[1428]: time="2025-02-13T19:36:32.362174417Z" level=info msg="loading plugin \"io.containerd.internal.v1.opt\"..." type=io.containerd.internal.v1 Feb 13 19:36:32.362421 containerd[1428]: time="2025-02-13T19:36:32.362395482Z" level=info msg="loading plugin \"io.containerd.warning.v1.deprecations\"..." type=io.containerd.warning.v1 Feb 13 19:36:32.362421 containerd[1428]: time="2025-02-13T19:36:32.362417463Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362521 containerd[1428]: time="2025-02-13T19:36:32.362501791Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." error="no scratch file generator: skip plugin" type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362521 containerd[1428]: time="2025-02-13T19:36:32.362518031Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362736 containerd[1428]: time="2025-02-13T19:36:32.362707447Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." error="path /var/lib/containerd/io.containerd.snapshotter.v1.btrfs (ext4) must be a btrfs filesystem to be used with the btrfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362736 containerd[1428]: time="2025-02-13T19:36:32.362727324Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362778 containerd[1428]: time="2025-02-13T19:36:32.362741430Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." error="devmapper not configured: skip plugin" type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362778 containerd[1428]: time="2025-02-13T19:36:32.362751329Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.362856 containerd[1428]: time="2025-02-13T19:36:32.362838823Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.363139 containerd[1428]: time="2025-02-13T19:36:32.363108529Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.zfs\"..." type=io.containerd.snapshotter.v1 Feb 13 19:36:32.363269 containerd[1428]: time="2025-02-13T19:36:32.363242530Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.zfs\"..." error="path /var/lib/containerd/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter: skip plugin" type=io.containerd.snapshotter.v1 Feb 13 19:36:32.363269 containerd[1428]: time="2025-02-13T19:36:32.363260774Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1 Feb 13 19:36:32.363378 containerd[1428]: time="2025-02-13T19:36:32.363355522Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1 Feb 13 19:36:32.363428 containerd[1428]: time="2025-02-13T19:36:32.363412879Z" level=info msg="metadata content store policy set" policy=shared Feb 13 19:36:32.504519 containerd[1428]: time="2025-02-13T19:36:32.504351830Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1 Feb 13 19:36:32.504519 containerd[1428]: time="2025-02-13T19:36:32.504454142Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1 Feb 13 19:36:32.504519 containerd[1428]: time="2025-02-13T19:36:32.504498996Z" level=info msg="loading plugin \"io.containerd.lease.v1.manager\"..." type=io.containerd.lease.v1 Feb 13 19:36:32.504519 containerd[1428]: time="2025-02-13T19:36:32.504521548Z" level=info msg="loading plugin \"io.containerd.streaming.v1.manager\"..." type=io.containerd.streaming.v1 Feb 13 19:36:32.504705 containerd[1428]: time="2025-02-13T19:36:32.504542107Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." type=io.containerd.runtime.v1 Feb 13 19:36:32.504803 containerd[1428]: time="2025-02-13T19:36:32.504768150Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." type=io.containerd.monitor.v1 Feb 13 19:36:32.505112 containerd[1428]: time="2025-02-13T19:36:32.505077490Z" level=info msg="loading plugin \"io.containerd.runtime.v2.task\"..." type=io.containerd.runtime.v2 Feb 13 19:36:32.505244 containerd[1428]: time="2025-02-13T19:36:32.505213666Z" level=info msg="loading plugin \"io.containerd.runtime.v2.shim\"..." type=io.containerd.runtime.v2 Feb 13 19:36:32.505268 containerd[1428]: time="2025-02-13T19:36:32.505239765Z" level=info msg="loading plugin \"io.containerd.sandbox.store.v1.local\"..." type=io.containerd.sandbox.store.v1 Feb 13 19:36:32.505268 containerd[1428]: time="2025-02-13T19:36:32.505258540Z" level=info msg="loading plugin \"io.containerd.sandbox.controller.v1.local\"..." type=io.containerd.sandbox.controller.v1 Feb 13 19:36:32.505318 containerd[1428]: time="2025-02-13T19:36:32.505276223Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505318 containerd[1428]: time="2025-02-13T19:36:32.505293686Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505318 containerd[1428]: time="2025-02-13T19:36:32.505309495Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505381 containerd[1428]: time="2025-02-13T19:36:32.505327850Z" level=info msg="loading plugin \"io.containerd.service.v1.images-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505381 containerd[1428]: time="2025-02-13T19:36:32.505346114Z" level=info msg="loading plugin \"io.containerd.service.v1.introspection-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505381 containerd[1428]: time="2025-02-13T19:36:32.505361513Z" level=info msg="loading plugin \"io.containerd.service.v1.namespaces-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505381 containerd[1428]: time="2025-02-13T19:36:32.505376381Z" level=info msg="loading plugin \"io.containerd.service.v1.snapshots-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505391920Z" level=info msg="loading plugin \"io.containerd.service.v1.tasks-service\"..." type=io.containerd.service.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505416877Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505434249Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505448907Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505485155Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505502477Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505519710Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505535 containerd[1428]: time="2025-02-13T19:36:32.505535479Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505553122Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505570314Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandbox-controllers\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505589841Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandboxes\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505604799Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505621601Z" level=info msg="loading plugin \"io.containerd.grpc.v1.streaming\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505637571Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505683 containerd[1428]: time="2025-02-13T19:36:32.505655845Z" level=info msg="loading plugin \"io.containerd.transfer.v1.local\"..." type=io.containerd.transfer.v1 Feb 13 19:36:32.505807 containerd[1428]: time="2025-02-13T19:36:32.505698615Z" level=info msg="loading plugin \"io.containerd.grpc.v1.transfer\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505807 containerd[1428]: time="2025-02-13T19:36:32.505716819Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505807 containerd[1428]: time="2025-02-13T19:36:32.505731336Z" level=info msg="loading plugin \"io.containerd.internal.v1.restart\"..." type=io.containerd.internal.v1 Feb 13 19:36:32.505807 containerd[1428]: time="2025-02-13T19:36:32.505792802Z" level=info msg="loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." type=io.containerd.tracing.processor.v1 Feb 13 19:36:32.505875 containerd[1428]: time="2025-02-13T19:36:32.505815214Z" level=info msg="skip loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.tracing.processor.v1 Feb 13 19:36:32.505875 containerd[1428]: time="2025-02-13T19:36:32.505829550Z" level=info msg="loading plugin \"io.containerd.internal.v1.tracing\"..." type=io.containerd.internal.v1 Feb 13 19:36:32.505875 containerd[1428]: time="2025-02-13T19:36:32.505846071Z" level=info msg="skip loading plugin \"io.containerd.internal.v1.tracing\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.internal.v1 Feb 13 19:36:32.505875 containerd[1428]: time="2025-02-13T19:36:32.505860278Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.505962 containerd[1428]: time="2025-02-13T19:36:32.505877230Z" level=info msg="loading plugin \"io.containerd.nri.v1.nri\"..." type=io.containerd.nri.v1 Feb 13 19:36:32.505962 containerd[1428]: time="2025-02-13T19:36:32.505900964Z" level=info msg="NRI interface is disabled by configuration." Feb 13 19:36:32.505962 containerd[1428]: time="2025-02-13T19:36:32.505914991Z" level=info msg="loading plugin \"io.containerd.grpc.v1.cri\"..." type=io.containerd.grpc.v1 Feb 13 19:36:32.506360 containerd[1428]: time="2025-02-13T19:36:32.506287780Z" level=info msg="Start cri plugin with config {PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc DefaultRuntime:{Type: Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:} UntrustedWorkloadRuntime:{Type: Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:} Runtimes:map[runc:{Type:io.containerd.runc.v2 Path: Engine: PodAnnotations:[] ContainerAnnotations:[] Root: Options:map[SystemdCgroup:true] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: SandboxMode:podsandbox}] NoPivot:false DisableSnapshotAnnotations:true DiscardUnpackedLayers:false IgnoreBlockIONotEnabledErrors:false IgnoreRdtNotEnabledErrors:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginSetupSerially:false NetworkPluginConfTemplate: IPPreference:} Registry:{ConfigPath: Mirrors:map[] Configs:map[] Auths:map[] Headers:map[]} ImageDecryption:{KeyModel:node} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:true SelinuxCategoryRange:1024 SandboxImage:registry.k8s.io/pause:3.8 StatsCollectPeriod:10 SystemdCgroup:false EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false UnsetSeccompProfile: TolerateMissingHugetlbController:true DisableHugetlbController:true DeviceOwnershipFromSecurityContext:false IgnoreImageDefinedVolumes:false NetNSMountsUnderStateDir:false EnableUnprivilegedPorts:false EnableUnprivilegedICMP:false EnableCDI:false CDISpecDirs:[/etc/cdi /var/run/cdi] ImagePullProgressTimeout:5m0s DrainExecSyncIOTimeout:0s ImagePullWithSyncFs:false IgnoreDeprecationWarnings:[]} ContainerdRootDir:/var/lib/containerd ContainerdEndpoint:/run/containerd/containerd.sock RootDir:/var/lib/containerd/io.containerd.grpc.v1.cri StateDir:/run/containerd/io.containerd.grpc.v1.cri}" Feb 13 19:36:32.506360 containerd[1428]: time="2025-02-13T19:36:32.506353182Z" level=info msg="Connect containerd service" Feb 13 19:36:32.506546 containerd[1428]: time="2025-02-13T19:36:32.506393468Z" level=info msg="using legacy CRI server" Feb 13 19:36:32.506546 containerd[1428]: time="2025-02-13T19:36:32.506403537Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Feb 13 19:36:32.506583 containerd[1428]: time="2025-02-13T19:36:32.506554019Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\"" Feb 13 19:36:32.508425 containerd[1428]: time="2025-02-13T19:36:32.508368852Z" 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" Feb 13 19:36:32.508585 containerd[1428]: time="2025-02-13T19:36:32.508517009Z" level=info msg="Start subscribing containerd event" Feb 13 19:36:32.508585 containerd[1428]: time="2025-02-13T19:36:32.508579066Z" level=info msg="Start recovering state" Feb 13 19:36:32.508745 containerd[1428]: time="2025-02-13T19:36:32.508659096Z" level=info msg="Start event monitor" Feb 13 19:36:32.508745 containerd[1428]: time="2025-02-13T19:36:32.508674615Z" level=info msg="Start snapshots syncer" Feb 13 19:36:32.508745 containerd[1428]: time="2025-02-13T19:36:32.508686467Z" level=info msg="Start cni network conf syncer for default" Feb 13 19:36:32.508745 containerd[1428]: time="2025-02-13T19:36:32.508697738Z" level=info msg="Start streaming server" Feb 13 19:36:32.508841 containerd[1428]: time="2025-02-13T19:36:32.508766287Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Feb 13 19:36:32.508841 containerd[1428]: time="2025-02-13T19:36:32.508831179Z" level=info msg=serving... address=/run/containerd/containerd.sock Feb 13 19:36:32.508951 containerd[1428]: time="2025-02-13T19:36:32.508929112Z" level=info msg="containerd successfully booted in 0.173196s" Feb 13 19:36:32.509088 systemd[1]: Started containerd.service - containerd container runtime. Feb 13 19:36:32.914736 systemd-networkd[1358]: eth0: Gained IPv6LL Feb 13 19:36:32.918197 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Feb 13 19:36:32.920209 systemd[1]: Reached target network-online.target - Network is Online. Feb 13 19:36:32.932716 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Feb 13 19:36:32.935138 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Feb 13 19:36:32.954995 systemd[1]: coreos-metadata.service: Deactivated successfully. Feb 13 19:36:32.955300 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Feb 13 19:36:32.957138 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Feb 13 19:36:32.969753 systemd[1]: Starting etcd-member.service - etcd (System Application Container)... Feb 13 19:36:32.970957 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Feb 13 19:36:32.971374 (-wrapper)[1500]: etcd-member.service: Referenced but unset environment variable evaluates to an empty string: ETCD_OPTS Feb 13 19:36:33.080670 systemd[1]: Starting docker.service - Docker Application Container Engine... Feb 13 19:36:33.080818 (dockerd)[1512]: 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 Feb 13 19:36:33.141558 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Feb 13 19:36:33.143919 systemd[1]: Started sshd@0-10.0.0.57:22-10.0.0.1:44038.service - OpenSSH per-connection server daemon (10.0.0.1:44038). Feb 13 19:36:33.194455 sshd[1514]: Accepted publickey for core from 10.0.0.1 port 44038 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:33.196156 sshd-session[1514]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:33.204199 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Feb 13 19:36:33.214771 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Feb 13 19:36:33.218523 systemd-logind[1412]: New session 1 of user core. Feb 13 19:36:33.226751 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Feb 13 19:36:33.234730 systemd[1]: Starting user@500.service - User Manager for UID 500... Feb 13 19:36:33.240142 (systemd)[1523]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Feb 13 19:36:33.325715 dockerd[1512]: time="2025-02-13T19:36:33.325645996Z" level=info msg="Starting up" Feb 13 19:36:33.349247 systemd[1523]: Queued start job for default target default.target. Feb 13 19:36:33.359032 systemd[1523]: Created slice app.slice - User Application Slice. Feb 13 19:36:33.359065 systemd[1523]: Reached target paths.target - Paths. Feb 13 19:36:33.359083 systemd[1523]: Reached target timers.target - Timers. Feb 13 19:36:33.360730 systemd[1523]: Starting dbus.socket - D-Bus User Message Bus Socket... Feb 13 19:36:33.372632 systemd[1523]: Listening on dbus.socket - D-Bus User Message Bus Socket. Feb 13 19:36:33.372766 systemd[1523]: Reached target sockets.target - Sockets. Feb 13 19:36:33.372787 systemd[1523]: Reached target basic.target - Basic System. Feb 13 19:36:33.372829 systemd[1523]: Reached target default.target - Main User Target. Feb 13 19:36:33.372871 systemd[1523]: Startup finished in 125ms. Feb 13 19:36:33.373788 systemd[1]: Started user@500.service - User Manager for UID 500. Feb 13 19:36:33.382603 systemd[1]: Started session-1.scope - Session 1 of User core. Feb 13 19:36:33.443785 systemd[1]: Started sshd@1-10.0.0.57:22-10.0.0.1:44042.service - OpenSSH per-connection server daemon (10.0.0.1:44042). Feb 13 19:36:33.493198 sshd[1550]: Accepted publickey for core from 10.0.0.1 port 44042 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:33.494573 sshd-session[1550]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:33.498513 systemd-logind[1412]: New session 2 of user core. Feb 13 19:36:33.512596 systemd[1]: Started session-2.scope - Session 2 of User core. Feb 13 19:36:33.565699 sshd[1552]: Connection closed by 10.0.0.1 port 44042 Feb 13 19:36:33.566007 sshd-session[1550]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:33.589928 systemd[1]: sshd@1-10.0.0.57:22-10.0.0.1:44042.service: Deactivated successfully. Feb 13 19:36:33.591482 systemd[1]: session-2.scope: Deactivated successfully. Feb 13 19:36:33.592697 systemd-logind[1412]: Session 2 logged out. Waiting for processes to exit. Feb 13 19:36:33.593933 systemd[1]: Started sshd@2-10.0.0.57:22-10.0.0.1:44058.service - OpenSSH per-connection server daemon (10.0.0.1:44058). Feb 13 19:36:33.596261 systemd-logind[1412]: Removed session 2. Feb 13 19:36:33.655809 sshd[1557]: Accepted publickey for core from 10.0.0.1 port 44058 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:33.657631 sshd-session[1557]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:33.661967 systemd-logind[1412]: New session 3 of user core. Feb 13 19:36:33.677596 systemd[1]: Started session-3.scope - Session 3 of User core. Feb 13 19:36:33.733302 sshd[1559]: Connection closed by 10.0.0.1 port 44058 Feb 13 19:36:33.733646 sshd-session[1557]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:33.737725 systemd[1]: sshd@2-10.0.0.57:22-10.0.0.1:44058.service: Deactivated successfully. Feb 13 19:36:33.739957 systemd[1]: session-3.scope: Deactivated successfully. Feb 13 19:36:33.741343 systemd-logind[1412]: Session 3 logged out. Waiting for processes to exit. Feb 13 19:36:33.742958 systemd-logind[1412]: Removed session 3. Feb 13 19:36:33.744667 dockerd[1512]: time="2025-02-13T19:36:33.744598251Z" level=info msg="Loading containers: start." Feb 13 19:36:33.944488 kernel: Initializing XFRM netlink socket Feb 13 19:36:34.018330 systemd-networkd[1358]: docker0: Link UP Feb 13 19:36:34.056849 dockerd[1512]: time="2025-02-13T19:36:34.056787767Z" level=info msg="Loading containers: done." Feb 13 19:36:34.113272 dockerd[1512]: time="2025-02-13T19:36:34.113211922Z" 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 Feb 13 19:36:34.113452 dockerd[1512]: time="2025-02-13T19:36:34.113323451Z" level=info msg="Docker daemon" commit=8b539b8df24032dabeaaa099cf1d0535ef0286a3 containerd-snapshotter=false storage-driver=overlay2 version=27.2.1 Feb 13 19:36:34.113518 dockerd[1512]: time="2025-02-13T19:36:34.113494161Z" level=info msg="Daemon has completed initialization" Feb 13 19:36:34.225820 systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck3983494748-merged.mount: Deactivated successfully. Feb 13 19:36:34.633128 dockerd[1512]: time="2025-02-13T19:36:34.633056641Z" level=info msg="API listen on /run/docker.sock" Feb 13 19:36:34.633334 systemd[1]: Started docker.service - Docker Application Container Engine. Feb 13 19:36:34.635068 etcd-wrapper[1504]: Error response from daemon: No such container: etcd-member Feb 13 19:36:34.649951 etcd-wrapper[1717]: Error response from daemon: No such container: etcd-member Feb 13 19:36:34.678215 etcd-wrapper[1736]: Unable to find image 'quay.io/coreos/etcd:v3.5.16' locally Feb 13 19:36:37.095844 etcd-wrapper[1736]: v3.5.16: Pulling from coreos/etcd Feb 13 19:36:37.363734 etcd-wrapper[1736]: 804c8aba2cc6: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 2ae710cd8bfe: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: d462aa345367: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 0f8b424aa0b9: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: d557676654e5: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: c8022d07192e: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: d858cbc252ad: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 1069fc2daed1: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: b40161cd83fc: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 5318d93a3a65: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 307c1adadb60: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: fbb01d9e9dc9: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: fbfea02ac3cf: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 8c26e4bf18e2: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: 1e59a65f8816: Pulling fs layer Feb 13 19:36:37.363869 etcd-wrapper[1736]: ffbd4ca5f0bd: Pulling fs layer Feb 13 19:36:37.364258 etcd-wrapper[1736]: 0f8b424aa0b9: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: d557676654e5: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: c8022d07192e: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: d858cbc252ad: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: 1069fc2daed1: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: b40161cd83fc: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: 5318d93a3a65: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: 307c1adadb60: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: fbb01d9e9dc9: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: fbfea02ac3cf: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: 8c26e4bf18e2: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: 1e59a65f8816: Waiting Feb 13 19:36:37.364258 etcd-wrapper[1736]: ffbd4ca5f0bd: Waiting Feb 13 19:36:37.601858 etcd-wrapper[1736]: 2ae710cd8bfe: Download complete Feb 13 19:36:37.823448 etcd-wrapper[1736]: 0f8b424aa0b9: Download complete Feb 13 19:36:38.070660 etcd-wrapper[1736]: d557676654e5: Verifying Checksum Feb 13 19:36:38.070660 etcd-wrapper[1736]: d557676654e5: Download complete Feb 13 19:36:38.338878 etcd-wrapper[1736]: d462aa345367: Verifying Checksum Feb 13 19:36:38.338878 etcd-wrapper[1736]: d462aa345367: Download complete Feb 13 19:36:38.446478 etcd-wrapper[1736]: c8022d07192e: Verifying Checksum Feb 13 19:36:38.446478 etcd-wrapper[1736]: c8022d07192e: Download complete Feb 13 19:36:38.543484 etcd-wrapper[1736]: d858cbc252ad: Verifying Checksum Feb 13 19:36:38.543484 etcd-wrapper[1736]: d858cbc252ad: Download complete Feb 13 19:36:38.764641 etcd-wrapper[1736]: b40161cd83fc: Download complete Feb 13 19:36:39.197536 etcd-wrapper[1736]: 5318d93a3a65: Verifying Checksum Feb 13 19:36:39.197536 etcd-wrapper[1736]: 5318d93a3a65: Download complete Feb 13 19:36:39.286368 etcd-wrapper[1736]: 804c8aba2cc6: Download complete Feb 13 19:36:39.468695 etcd-wrapper[1736]: 307c1adadb60: Verifying Checksum Feb 13 19:36:39.468695 etcd-wrapper[1736]: 307c1adadb60: Download complete Feb 13 19:36:39.483165 etcd-wrapper[1736]: 804c8aba2cc6: Pull complete Feb 13 19:36:39.501674 systemd[1]: var-lib-docker-overlay2-b69012c34822ad67fa0e5ca15167458edb2ac44fcc02d77cdf2e5ba91c169c81-merged.mount: Deactivated successfully. Feb 13 19:36:39.551248 etcd-wrapper[1736]: 2ae710cd8bfe: Pull complete Feb 13 19:36:39.563588 etcd-wrapper[1736]: fbb01d9e9dc9: Verifying Checksum Feb 13 19:36:39.563588 etcd-wrapper[1736]: fbb01d9e9dc9: Download complete Feb 13 19:36:39.697992 etcd-wrapper[1736]: fbfea02ac3cf: Verifying Checksum Feb 13 19:36:39.697992 etcd-wrapper[1736]: fbfea02ac3cf: Download complete Feb 13 19:36:39.893646 etcd-wrapper[1736]: 8c26e4bf18e2: Verifying Checksum Feb 13 19:36:39.893646 etcd-wrapper[1736]: 8c26e4bf18e2: Download complete Feb 13 19:36:39.929357 etcd-wrapper[1736]: 1e59a65f8816: Verifying Checksum Feb 13 19:36:39.929559 etcd-wrapper[1736]: 1e59a65f8816: Download complete Feb 13 19:36:39.973765 systemd[1]: var-lib-docker-overlay2-aa5e113292fee94940ddc40e3c261f46504bb28a0e261edda7e42770c222c87c-merged.mount: Deactivated successfully. Feb 13 19:36:40.095308 etcd-wrapper[1736]: d462aa345367: Pull complete Feb 13 19:36:40.109202 etcd-wrapper[1736]: ffbd4ca5f0bd: Verifying Checksum Feb 13 19:36:40.109202 etcd-wrapper[1736]: ffbd4ca5f0bd: Download complete Feb 13 19:36:40.117700 etcd-wrapper[1736]: 0f8b424aa0b9: Pull complete Feb 13 19:36:40.146977 etcd-wrapper[1736]: d557676654e5: Pull complete Feb 13 19:36:40.169791 etcd-wrapper[1736]: c8022d07192e: Pull complete Feb 13 19:36:40.192958 etcd-wrapper[1736]: d858cbc252ad: Pull complete Feb 13 19:36:40.495686 systemd[1]: var-lib-docker-overlay2-3e78fbf82917644898dd2ebcbfb2480d8e91ddd6ddbdea3f9f2a8bfcbbd7380f-merged.mount: Deactivated successfully. Feb 13 19:36:42.638438 etcd-wrapper[1736]: 1069fc2daed1: Verifying Checksum Feb 13 19:36:42.638438 etcd-wrapper[1736]: 1069fc2daed1: Download complete Feb 13 19:36:42.650275 systemd[1]: var-lib-docker-overlay2-de6b03aaf1cadb951f0bdeccf7d62066bdc96a3b9ea687c28af0cf0035ef2678-merged.mount: Deactivated successfully. Feb 13 19:36:42.664164 etcd-wrapper[1736]: 1069fc2daed1: Pull complete Feb 13 19:36:42.680042 systemd[1]: var-lib-docker-overlay2-86e2eb808e1d69f13ccfa3cceea7410d0ccdb85753b13449a6d77b8701c62368-merged.mount: Deactivated successfully. Feb 13 19:36:42.691734 etcd-wrapper[1736]: b40161cd83fc: Pull complete Feb 13 19:36:42.717254 etcd-wrapper[1736]: 5318d93a3a65: Pull complete Feb 13 19:36:42.745452 etcd-wrapper[1736]: 307c1adadb60: Pull complete Feb 13 19:36:43.056605 etcd-wrapper[1736]: fbb01d9e9dc9: Pull complete Feb 13 19:36:43.221905 etcd-wrapper[1736]: fbfea02ac3cf: Pull complete Feb 13 19:36:43.362988 etcd-wrapper[1736]: 8c26e4bf18e2: Pull complete Feb 13 19:36:43.388416 etcd-wrapper[1736]: 1e59a65f8816: Pull complete Feb 13 19:36:43.413313 etcd-wrapper[1736]: ffbd4ca5f0bd: Pull complete Feb 13 19:36:43.422212 etcd-wrapper[1736]: Digest: sha256:d967d98a12dc220a1a290794711dba7eba04b8ce465e12b02383d1bfbb33e159 Feb 13 19:36:43.425218 etcd-wrapper[1736]: Status: Downloaded newer image for quay.io/coreos/etcd:v3.5.16 Feb 13 19:36:43.537562 containerd[1428]: time="2025-02-13T19:36:43.537454124Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Feb 13 19:36:43.537562 containerd[1428]: time="2025-02-13T19:36:43.537535456Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Feb 13 19:36:43.537562 containerd[1428]: time="2025-02-13T19:36:43.537547749Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Feb 13 19:36:43.538058 containerd[1428]: time="2025-02-13T19:36:43.537633861Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Feb 13 19:36:43.556593 systemd[1]: Started docker-d2bda3d85d50f337f7551b76a3bc8a8aa2f63114ad04d582739e194acc1dacaf.scope - libcontainer container d2bda3d85d50f337f7551b76a3bc8a8aa2f63114ad04d582739e194acc1dacaf. Feb 13 19:36:43.571882 systemd-resolved[1271]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.606355Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_DATA_DIR","variable-value":"/var/lib/etcd"} Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.606474Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_NAME","variable-value":"428f8b7b87cd429097bd2d52a56c643c"} Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606520Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_URL=quay.io/coreos/etcd"} Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606532Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_TAG=v3.5.16"} Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606538Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_USER=etcd"} Feb 13 19:36:43.606706 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606543Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_SSL_DIR=/etc/ssl/certs"} Feb 13 19:36:43.606946 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606610Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Feb 13 19:36:43.606946 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.606643Z","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.57:2379"]} Feb 13 19:36:43.606946 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.606717Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Feb 13 19:36:43.606946 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.606730Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} Feb 13 19:36:43.607327 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.607158Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} Feb 13 19:36:43.607435 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.607276Z","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":"428f8b7b87cd429097bd2d52a56c643c","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.57:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"428f8b7b87cd429097bd2d52a56c643c=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"} Feb 13 19:36:43.610384 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.610170Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"2.540213ms"} Feb 13 19:36:43.614304 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614084Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} Feb 13 19:36:43.614457 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614200Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} Feb 13 19:36:43.614457 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614263Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} Feb 13 19:36:43.614457 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614272Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} Feb 13 19:36:43.614457 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614283Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} Feb 13 19:36:43.614955 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.614389Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Feb 13 19:36:43.619149 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:36:43.618946Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} Feb 13 19:36:43.620237 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.620058Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} Feb 13 19:36:43.621198 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.621016Z","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"} Feb 13 19:36:43.622186 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622001Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} Feb 13 19:36:43.622747 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622427Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} Feb 13 19:36:43.622747 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622502Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} Feb 13 19:36:43.623029 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622487Z","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"} Feb 13 19:36:43.623029 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622514Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} Feb 13 19:36:43.623029 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.622725Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Feb 13 19:36:43.624076 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.623772Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Feb 13 19:36:43.624076 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.623860Z","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"]} Feb 13 19:36:43.624913 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.624731Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} Feb 13 19:36:43.624913 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.624739Z","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.57:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} Feb 13 19:36:43.624913 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:43.624750Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} Feb 13 19:36:43.648323 systemd[1]: var-lib-docker-overlay2-47637363dd84cc0fd1475e32b77dbb5a9f6297a5989c98714c489b0d1eed86ed-merged.mount: Deactivated successfully. Feb 13 19:36:43.750938 systemd[1]: Started sshd@3-10.0.0.57:22-10.0.0.1:48068.service - OpenSSH per-connection server daemon (10.0.0.1:48068). Feb 13 19:36:43.797789 sshd[1884]: Accepted publickey for core from 10.0.0.1 port 48068 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:43.799217 sshd-session[1884]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:43.802835 systemd-logind[1412]: New session 4 of user core. Feb 13 19:36:43.814596 systemd[1]: Started session-4.scope - Session 4 of User core. Feb 13 19:36:43.867432 sshd[1886]: Connection closed by 10.0.0.1 port 48068 Feb 13 19:36:43.867753 sshd-session[1884]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:43.882013 systemd[1]: sshd@3-10.0.0.57:22-10.0.0.1:48068.service: Deactivated successfully. Feb 13 19:36:43.883648 systemd[1]: session-4.scope: Deactivated successfully. Feb 13 19:36:43.884979 systemd-logind[1412]: Session 4 logged out. Waiting for processes to exit. Feb 13 19:36:43.896694 systemd[1]: Started sshd@4-10.0.0.57:22-10.0.0.1:48076.service - OpenSSH per-connection server daemon (10.0.0.1:48076). Feb 13 19:36:43.897544 systemd-logind[1412]: Removed session 4. Feb 13 19:36:43.935850 sshd[1891]: Accepted publickey for core from 10.0.0.1 port 48076 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:43.937259 sshd-session[1891]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:43.941198 systemd-logind[1412]: New session 5 of user core. Feb 13 19:36:43.956615 systemd[1]: Started session-5.scope - Session 5 of User core. Feb 13 19:36:44.011008 sshd[1893]: Connection closed by 10.0.0.1 port 48076 Feb 13 19:36:44.011405 sshd-session[1891]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:44.015722 systemd[1]: sshd@4-10.0.0.57:22-10.0.0.1:48076.service: Deactivated successfully. Feb 13 19:36:44.017977 systemd[1]: session-5.scope: Deactivated successfully. Feb 13 19:36:44.018604 systemd-logind[1412]: Session 5 logged out. Waiting for processes to exit. Feb 13 19:36:44.019416 systemd-logind[1412]: Removed session 5. Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415226Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415276Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415313Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415325Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415332Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415340Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} Feb 13 19:36:44.415597 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.415348Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} Feb 13 19:36:44.439343 systemd[1]: Started etcd-member.service - etcd (System Application Container). Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.438766Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:428f8b7b87cd429097bd2d52a56c643c ClientURLs:[http://10.0.0.57:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.438771Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.438771Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.438931Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.439094Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} Feb 13 19:36:44.439642 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.439295Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Feb 13 19:36:44.439908 systemd[1]: Reached target multi-user.target - Multi-User System. Feb 13 19:36:44.440121 systemd[1]: Startup finished in 706ms (kernel) + 3.876s (initrd) + 14.294s (userspace) = 18.877s. Feb 13 19:36:44.440237 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.439765Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} Feb 13 19:36:44.457534 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.457207Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} Feb 13 19:36:44.457534 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.457279Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} Feb 13 19:36:44.457534 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:36:44.457312Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} Feb 13 19:36:54.022377 systemd[1]: Started sshd@5-10.0.0.57:22-10.0.0.1:34630.service - OpenSSH per-connection server daemon (10.0.0.1:34630). Feb 13 19:36:54.064488 sshd[1900]: Accepted publickey for core from 10.0.0.1 port 34630 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.065869 sshd-session[1900]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.069271 systemd-logind[1412]: New session 6 of user core. Feb 13 19:36:54.084580 systemd[1]: Started session-6.scope - Session 6 of User core. Feb 13 19:36:54.136708 sshd[1902]: Connection closed by 10.0.0.1 port 34630 Feb 13 19:36:54.137022 sshd-session[1900]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.151797 systemd[1]: sshd@5-10.0.0.57:22-10.0.0.1:34630.service: Deactivated successfully. Feb 13 19:36:54.153184 systemd[1]: session-6.scope: Deactivated successfully. Feb 13 19:36:54.154470 systemd-logind[1412]: Session 6 logged out. Waiting for processes to exit. Feb 13 19:36:54.155608 systemd[1]: Started sshd@6-10.0.0.57:22-10.0.0.1:34642.service - OpenSSH per-connection server daemon (10.0.0.1:34642). Feb 13 19:36:54.156357 systemd-logind[1412]: Removed session 6. Feb 13 19:36:54.197338 sshd[1907]: Accepted publickey for core from 10.0.0.1 port 34642 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.198631 sshd-session[1907]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.202278 systemd-logind[1412]: New session 7 of user core. Feb 13 19:36:54.215589 systemd[1]: Started session-7.scope - Session 7 of User core. Feb 13 19:36:54.263540 sshd[1909]: Connection closed by 10.0.0.1 port 34642 Feb 13 19:36:54.263853 sshd-session[1907]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.272925 systemd[1]: sshd@6-10.0.0.57:22-10.0.0.1:34642.service: Deactivated successfully. Feb 13 19:36:54.274569 systemd[1]: session-7.scope: Deactivated successfully. Feb 13 19:36:54.275795 systemd-logind[1412]: Session 7 logged out. Waiting for processes to exit. Feb 13 19:36:54.276970 systemd[1]: Started sshd@7-10.0.0.57:22-10.0.0.1:34644.service - OpenSSH per-connection server daemon (10.0.0.1:34644). Feb 13 19:36:54.277596 systemd-logind[1412]: Removed session 7. Feb 13 19:36:54.319313 sshd[1914]: Accepted publickey for core from 10.0.0.1 port 34644 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.320665 sshd-session[1914]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.324170 systemd-logind[1412]: New session 8 of user core. Feb 13 19:36:54.333580 systemd[1]: Started session-8.scope - Session 8 of User core. Feb 13 19:36:54.385568 sshd[1916]: Connection closed by 10.0.0.1 port 34644 Feb 13 19:36:54.385921 sshd-session[1914]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.401121 systemd[1]: sshd@7-10.0.0.57:22-10.0.0.1:34644.service: Deactivated successfully. Feb 13 19:36:54.402675 systemd[1]: session-8.scope: Deactivated successfully. Feb 13 19:36:54.404288 systemd-logind[1412]: Session 8 logged out. Waiting for processes to exit. Feb 13 19:36:54.405547 systemd[1]: Started sshd@8-10.0.0.57:22-10.0.0.1:34660.service - OpenSSH per-connection server daemon (10.0.0.1:34660). Feb 13 19:36:54.406397 systemd-logind[1412]: Removed session 8. Feb 13 19:36:54.447212 sshd[1921]: Accepted publickey for core from 10.0.0.1 port 34660 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.448596 sshd-session[1921]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.452254 systemd-logind[1412]: New session 9 of user core. Feb 13 19:36:54.461589 systemd[1]: Started session-9.scope - Session 9 of User core. Feb 13 19:36:54.519098 sudo[1924]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/setenforce 1 Feb 13 19:36:54.519422 sudo[1924]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Feb 13 19:36:54.535907 sudo[1924]: pam_unix(sudo:session): session closed for user root Feb 13 19:36:54.537254 sshd[1923]: Connection closed by 10.0.0.1 port 34660 Feb 13 19:36:54.537678 sshd-session[1921]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.556321 systemd[1]: sshd@8-10.0.0.57:22-10.0.0.1:34660.service: Deactivated successfully. Feb 13 19:36:54.557922 systemd[1]: session-9.scope: Deactivated successfully. Feb 13 19:36:54.559300 systemd-logind[1412]: Session 9 logged out. Waiting for processes to exit. Feb 13 19:36:54.560633 systemd[1]: Started sshd@9-10.0.0.57:22-10.0.0.1:34674.service - OpenSSH per-connection server daemon (10.0.0.1:34674). Feb 13 19:36:54.561556 systemd-logind[1412]: Removed session 9. Feb 13 19:36:54.602560 sshd[1929]: Accepted publickey for core from 10.0.0.1 port 34674 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.603790 sshd-session[1929]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.607642 systemd-logind[1412]: New session 10 of user core. Feb 13 19:36:54.617577 systemd[1]: Started session-10.scope - Session 10 of User core. Feb 13 19:36:54.669062 sudo[1933]: 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 Feb 13 19:36:54.669389 sudo[1933]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Feb 13 19:36:54.672486 sudo[1933]: pam_unix(sudo:session): session closed for user root Feb 13 19:36:54.677804 sudo[1932]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/systemctl restart audit-rules Feb 13 19:36:54.678108 sudo[1932]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Feb 13 19:36:54.692739 systemd[1]: Starting audit-rules.service - Load Audit Rules... Feb 13 19:36:54.719503 augenrules[1955]: No rules Feb 13 19:36:54.721079 systemd[1]: audit-rules.service: Deactivated successfully. Feb 13 19:36:54.721338 systemd[1]: Finished audit-rules.service - Load Audit Rules. Feb 13 19:36:54.722656 sudo[1932]: pam_unix(sudo:session): session closed for user root Feb 13 19:36:54.723931 sshd[1931]: Connection closed by 10.0.0.1 port 34674 Feb 13 19:36:54.724309 sshd-session[1929]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.733829 systemd[1]: sshd@9-10.0.0.57:22-10.0.0.1:34674.service: Deactivated successfully. Feb 13 19:36:54.735201 systemd[1]: session-10.scope: Deactivated successfully. Feb 13 19:36:54.736485 systemd-logind[1412]: Session 10 logged out. Waiting for processes to exit. Feb 13 19:36:54.737603 systemd[1]: Started sshd@10-10.0.0.57:22-10.0.0.1:34690.service - OpenSSH per-connection server daemon (10.0.0.1:34690). Feb 13 19:36:54.738269 systemd-logind[1412]: Removed session 10. Feb 13 19:36:54.790423 sshd[1963]: Accepted publickey for core from 10.0.0.1 port 34690 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.791698 sshd-session[1963]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.795122 systemd-logind[1412]: New session 11 of user core. Feb 13 19:36:54.805570 systemd[1]: Started session-11.scope - Session 11 of User core. Feb 13 19:36:54.853576 sshd[1965]: Connection closed by 10.0.0.1 port 34690 Feb 13 19:36:54.853874 sshd-session[1963]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:54.868841 systemd[1]: sshd@10-10.0.0.57:22-10.0.0.1:34690.service: Deactivated successfully. Feb 13 19:36:54.870228 systemd[1]: session-11.scope: Deactivated successfully. Feb 13 19:36:54.871539 systemd-logind[1412]: Session 11 logged out. Waiting for processes to exit. Feb 13 19:36:54.872633 systemd[1]: Started sshd@11-10.0.0.57:22-10.0.0.1:34700.service - OpenSSH per-connection server daemon (10.0.0.1:34700). Feb 13 19:36:54.873287 systemd-logind[1412]: Removed session 11. Feb 13 19:36:54.913794 sshd[1972]: Accepted publickey for core from 10.0.0.1 port 34700 ssh2: RSA SHA256:Uh4KadtCLzIKC55xBX+WFJWCeY6fGIIe31vecjZIJAI Feb 13 19:36:54.915031 sshd-session[1972]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Feb 13 19:36:54.918370 systemd-logind[1412]: New session 12 of user core. Feb 13 19:36:54.927557 systemd[1]: Started session-12.scope - Session 12 of User core. Feb 13 19:36:55.065953 sshd[1974]: Connection closed by 10.0.0.1 port 34700 Feb 13 19:36:55.066229 sshd-session[1972]: pam_unix(sshd:session): session closed for user core Feb 13 19:36:55.070117 systemd[1]: sshd@11-10.0.0.57:22-10.0.0.1:34700.service: Deactivated successfully. Feb 13 19:36:55.071956 systemd[1]: session-12.scope: Deactivated successfully. Feb 13 19:36:55.072494 systemd-logind[1412]: Session 12 logged out. Waiting for processes to exit. Feb 13 19:36:55.073301 systemd-logind[1412]: Removed session 12. Feb 13 19:37:17.585758 update_engine[1415]: I20250213 19:37:17.585669 1415 update_attempter.cc:509] Updating boot flags... Feb 13 19:37:17.609486 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1992) Feb 13 19:37:17.688538 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1991) Feb 13 19:37:17.711542 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1991) Feb 13 19:37:41.954977 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:41.954650Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"146.294425ms","expected-duration":"100ms","prefix":"","request":"header: lease_grant:","response":"size:42"} Feb 13 19:37:41.954977 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:41.954720Z","caller":"traceutil/trace.go:171","msg":"trace[1187050342] linearizableReadLoop","detail":"{readStateIndex:229; appliedIndex:228; }","duration":"174.46016ms","start":"2025-02-13T19:37:41.780248Z","end":"2025-02-13T19:37:41.954708Z","steps":["trace[1187050342] 'read index received' (duration: 27.972863ms)","trace[1187050342] 'applied index is now lower than readState.Index' (duration: 146.486436ms)"],"step_count":2} Feb 13 19:37:41.954977 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:41.954804Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"174.545201ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/ranges/serviceips\" limit:1 ","response":"range_response_count:1 size:115"} Feb 13 19:37:41.954977 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:41.954828Z","caller":"traceutil/trace.go:171","msg":"trace[1580068292] range","detail":"{range_begin:/registry/ranges/serviceips; range_end:; response_count:1; response_revision:222; }","duration":"174.594683ms","start":"2025-02-13T19:37:41.780225Z","end":"2025-02-13T19:37:41.954820Z","steps":["trace[1580068292] 'agreement among raft nodes before linearized reading' (duration: 174.544227ms)"],"step_count":1} Feb 13 19:37:41.956840 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:41.956609Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"172.337098ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/localhost\" limit:1 ","response":"range_response_count:1 size:697"} Feb 13 19:37:41.956840 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:41.956631Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"172.074444ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-node-lease/localhost\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:37:41.956840 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:41.956639Z","caller":"traceutil/trace.go:171","msg":"trace[379673001] range","detail":"{range_begin:/registry/csinodes/localhost; range_end:; response_count:1; response_revision:224; }","duration":"172.378365ms","start":"2025-02-13T19:37:41.784253Z","end":"2025-02-13T19:37:41.956631Z","steps":["trace[379673001] 'agreement among raft nodes before linearized reading' (duration: 172.32225ms)"],"step_count":1} Feb 13 19:37:41.956840 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:41.956657Z","caller":"traceutil/trace.go:171","msg":"trace[1632486838] range","detail":"{range_begin:/registry/leases/kube-node-lease/localhost; range_end:; response_count:0; response_revision:224; }","duration":"172.109119ms","start":"2025-02-13T19:37:41.784540Z","end":"2025-02-13T19:37:41.956650Z","steps":["trace[1632486838] 'agreement among raft nodes before linearized reading' (duration: 172.070807ms)"],"step_count":1} Feb 13 19:37:43.619077 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:43.618593Z","caller":"traceutil/trace.go:171","msg":"trace[1884841242] transaction","detail":"{read_only:false; response_revision:349; number_of_response:1; }","duration":"110.336519ms","start":"2025-02-13T19:37:43.508229Z","end":"2025-02-13T19:37:43.618565Z","steps":["trace[1884841242] 'process raft request' (duration: 109.787286ms)"],"step_count":1} Feb 13 19:37:43.619077 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:43.618759Z","caller":"traceutil/trace.go:171","msg":"trace[389988248] transaction","detail":"{read_only:false; response_revision:350; number_of_response:1; }","duration":"101.827616ms","start":"2025-02-13T19:37:43.516926Z","end":"2025-02-13T19:37:43.618753Z","steps":["trace[389988248] 'process raft request' (duration: 101.599678ms)"],"step_count":1} Feb 13 19:37:43.619077 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:43.618784Z","caller":"traceutil/trace.go:171","msg":"trace[2025980486] transaction","detail":"{read_only:false; response_revision:351; number_of_response:1; }","duration":"101.22832ms","start":"2025-02-13T19:37:43.517551Z","end":"2025-02-13T19:37:43.618779Z","steps":["trace[2025980486] 'process raft request' (duration: 101.132239ms)"],"step_count":1} Feb 13 19:37:48.161550 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161033Z","caller":"traceutil/trace.go:171","msg":"trace[1264890763] transaction","detail":"{read_only:false; response_revision:418; number_of_response:1; }","duration":"180.671485ms","start":"2025-02-13T19:37:47.980345Z","end":"2025-02-13T19:37:48.161017Z","steps":["trace[1264890763] 'process raft request' (duration: 180.655746ms)"],"step_count":1} Feb 13 19:37:48.161550 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161113Z","caller":"traceutil/trace.go:171","msg":"trace[1534999369] transaction","detail":"{read_only:false; response_revision:416; number_of_response:1; }","duration":"202.792719ms","start":"2025-02-13T19:37:47.958296Z","end":"2025-02-13T19:37:48.161089Z","steps":["trace[1534999369] 'process raft request' (duration: 108.624595ms)","trace[1534999369] 'compare' (duration: 93.953852ms)"],"step_count":2} Feb 13 19:37:48.161550 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161158Z","caller":"traceutil/trace.go:171","msg":"trace[1643954729] linearizableReadLoop","detail":"{readStateIndex:429; appliedIndex:426; }","duration":"201.273075ms","start":"2025-02-13T19:37:47.959879Z","end":"2025-02-13T19:37:48.161152Z","steps":["trace[1643954729] 'read index received' (duration: 17.895136ms)","trace[1643954729] 'applied index is now lower than readState.Index' (duration: 183.377508ms)"],"step_count":2} Feb 13 19:37:48.161550 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161143Z","caller":"traceutil/trace.go:171","msg":"trace[143939575] transaction","detail":"{read_only:false; response_revision:417; number_of_response:1; }","duration":"202.575772ms","start":"2025-02-13T19:37:47.958558Z","end":"2025-02-13T19:37:48.161134Z","steps":["trace[143939575] 'process raft request' (duration: 202.409109ms)"],"step_count":1} Feb 13 19:37:48.161550 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.161220Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"201.326356ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/bgpfilters\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:37:48.162289 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161236Z","caller":"traceutil/trace.go:171","msg":"trace[1460301562] range","detail":"{range_begin:/registry/crd.projectcalico.org/bgpfilters; range_end:; response_count:0; response_revision:418; }","duration":"201.363967ms","start":"2025-02-13T19:37:47.959867Z","end":"2025-02-13T19:37:48.161231Z","steps":["trace[1460301562] 'agreement among raft nodes before linearized reading' (duration: 201.325535ms)"],"step_count":1} Feb 13 19:37:48.162289 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.161278Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"180.771353ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/kube-proxy-f5p94\" limit:1 ","response":"range_response_count:1 size:3418"} Feb 13 19:37:48.162289 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.161276Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"165.647914ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/replicaset-controller\" limit:1 ","response":"range_response_count:1 size:207"} Feb 13 19:37:48.162289 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161299Z","caller":"traceutil/trace.go:171","msg":"trace[1446680668] range","detail":"{range_begin:/registry/pods/kube-system/kube-proxy-f5p94; range_end:; response_count:1; response_revision:418; }","duration":"180.814735ms","start":"2025-02-13T19:37:47.980477Z","end":"2025-02-13T19:37:48.161291Z","steps":["trace[1446680668] 'agreement among raft nodes before linearized reading' (duration: 180.728263ms)"],"step_count":1} Feb 13 19:37:48.162394 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.161304Z","caller":"traceutil/trace.go:171","msg":"trace[808774099] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/replicaset-controller; range_end:; response_count:1; response_revision:418; }","duration":"165.689612ms","start":"2025-02-13T19:37:47.995606Z","end":"2025-02-13T19:37:48.161296Z","steps":["trace[808774099] 'agreement among raft nodes before linearized reading' (duration: 165.604813ms)"],"step_count":1} Feb 13 19:37:48.432607 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.432182Z","caller":"traceutil/trace.go:171","msg":"trace[1747562374] linearizableReadLoop","detail":"{readStateIndex:434; appliedIndex:433; }","duration":"190.676742ms","start":"2025-02-13T19:37:48.241491Z","end":"2025-02-13T19:37:48.432168Z","steps":["trace[1747562374] 'read index received' (duration: 113.94557ms)","trace[1747562374] 'applied index is now lower than readState.Index' (duration: 76.729038ms)"],"step_count":2} Feb 13 19:37:48.432607 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.432260Z","caller":"traceutil/trace.go:171","msg":"trace[1394784976] transaction","detail":"{read_only:false; response_revision:422; number_of_response:1; }","duration":"215.752321ms","start":"2025-02-13T19:37:48.216482Z","end":"2025-02-13T19:37:48.432234Z","steps":["trace[1394784976] 'process raft request' (duration: 138.893569ms)","trace[1394784976] 'compare' (duration: 76.716996ms)"],"step_count":2} Feb 13 19:37:48.432607 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.432337Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"190.836671ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/kube-proxy-f5p94\" limit:1 ","response":"range_response_count:1 size:4810"} Feb 13 19:37:48.432607 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.432364Z","caller":"traceutil/trace.go:171","msg":"trace[719120594] range","detail":"{range_begin:/registry/pods/kube-system/kube-proxy-f5p94; range_end:; response_count:1; response_revision:422; }","duration":"190.911243ms","start":"2025-02-13T19:37:48.241447Z","end":"2025-02-13T19:37:48.432358Z","steps":["trace[719120594] 'agreement among raft nodes before linearized reading' (duration: 190.785596ms)"],"step_count":1} Feb 13 19:37:48.463553 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.462983Z","caller":"traceutil/trace.go:171","msg":"trace[1655284019] transaction","detail":"{read_only:false; response_revision:424; number_of_response:1; }","duration":"218.110248ms","start":"2025-02-13T19:37:48.244860Z","end":"2025-02-13T19:37:48.462970Z","steps":["trace[1655284019] 'process raft request' (duration: 218.008026ms)"],"step_count":1} Feb 13 19:37:48.463553 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.462998Z","caller":"traceutil/trace.go:171","msg":"trace[1242534274] transaction","detail":"{read_only:false; response_revision:423; number_of_response:1; }","duration":"218.471477ms","start":"2025-02-13T19:37:48.244514Z","end":"2025-02-13T19:37:48.462986Z","steps":["trace[1242534274] 'process raft request' (duration: 218.298783ms)"],"step_count":1} Feb 13 19:37:48.463553 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.462989Z","caller":"traceutil/trace.go:171","msg":"trace[1890037181] transaction","detail":"{read_only:false; response_revision:426; number_of_response:1; }","duration":"215.030133ms","start":"2025-02-13T19:37:48.247950Z","end":"2025-02-13T19:37:48.462980Z","steps":["trace[1890037181] 'process raft request' (duration: 214.995718ms)"],"step_count":1} Feb 13 19:37:48.463553 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.463066Z","caller":"traceutil/trace.go:171","msg":"trace[332452316] transaction","detail":"{read_only:false; response_revision:425; number_of_response:1; }","duration":"218.133293ms","start":"2025-02-13T19:37:48.244927Z","end":"2025-02-13T19:37:48.463060Z","steps":["trace[332452316] 'process raft request' (duration: 217.960407ms)"],"step_count":1} Feb 13 19:37:48.707518 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.706923Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"137.289258ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Feb 13 19:37:48.707942 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.707077Z","caller":"traceutil/trace.go:171","msg":"trace[991777979] linearizableReadLoop","detail":"{readStateIndex:439; appliedIndex:434; }","duration":"274.845783ms","start":"2025-02-13T19:37:48.432221Z","end":"2025-02-13T19:37:48.707067Z","steps":["trace[991777979] 'read index received' (duration: 30.600716ms)","trace[991777979] 'applied index is now lower than readState.Index' (duration: 244.244546ms)"],"step_count":2} Feb 13 19:37:48.707942 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.707157Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"462.507182ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/localhost\" limit:1 ","response":"range_response_count:1 size:4128"} Feb 13 19:37:48.707942 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.707170Z","caller":"traceutil/trace.go:171","msg":"trace[2020903592] range","detail":"{range_begin:/registry/minions/localhost; range_end:; response_count:1; response_revision:428; }","duration":"462.529534ms","start":"2025-02-13T19:37:48.244636Z","end":"2025-02-13T19:37:48.707166Z","steps":["trace[2020903592] 'agreement among raft nodes before linearized reading' (duration: 462.465734ms)"],"step_count":1} Feb 13 19:37:48.707942 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.707191Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-02-13T19:37:48.244632Z","time spent":"462.552046ms","remote":"10.0.0.62:58800","response type":"/etcdserverpb.KV/Range","request count":0,"request size":31,"response count":1,"response size":4152,"request content":"key:\"/registry/minions/localhost\" limit:1 "} Feb 13 19:37:48.708178 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.707185Z","caller":"traceutil/trace.go:171","msg":"trace[988841926] transaction","detail":"{read_only:false; response_revision:427; number_of_response:1; }","duration":"347.751821ms","start":"2025-02-13T19:37:48.359411Z","end":"2025-02-13T19:37:48.707163Z","steps":["trace[988841926] 'process raft request' (duration: 209.951814ms)","trace[988841926] 'compare' (duration: 137.14119ms)"],"step_count":2} Feb 13 19:37:48.708178 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.707315Z","caller":"traceutil/trace.go:171","msg":"trace[1620523633] transaction","detail":"{read_only:false; response_revision:428; number_of_response:1; }","duration":"271.300034ms","start":"2025-02-13T19:37:48.436011Z","end":"2025-02-13T19:37:48.707311Z","steps":["trace[1620523633] 'process raft request' (duration: 271.012053ms)"],"step_count":1} Feb 13 19:37:48.708178 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:48.707366Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-02-13T19:37:48.359398Z","time spent":"347.879851ms","remote":"10.0.0.62:58912","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":492,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Feb 13 19:37:48.735841 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.735519Z","caller":"traceutil/trace.go:171","msg":"trace[1539360098] transaction","detail":"{read_only:false; response_revision:429; number_of_response:1; }","duration":"269.797391ms","start":"2025-02-13T19:37:48.465710Z","end":"2025-02-13T19:37:48.735507Z","steps":["trace[1539360098] 'process raft request' (duration: 269.622552ms)"],"step_count":1} Feb 13 19:37:48.735985 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.735642Z","caller":"traceutil/trace.go:171","msg":"trace[445323813] transaction","detail":"{read_only:false; response_revision:432; number_of_response:1; }","duration":"266.842832ms","start":"2025-02-13T19:37:48.468784Z","end":"2025-02-13T19:37:48.735627Z","steps":["trace[445323813] 'process raft request' (duration: 266.735751ms)"],"step_count":1} Feb 13 19:37:48.735985 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.735696Z","caller":"traceutil/trace.go:171","msg":"trace[3176585] transaction","detail":"{read_only:false; response_revision:430; number_of_response:1; }","duration":"268.493102ms","start":"2025-02-13T19:37:48.467197Z","end":"2025-02-13T19:37:48.735690Z","steps":["trace[3176585] 'process raft request' (duration: 268.225289ms)"],"step_count":1} Feb 13 19:37:48.735985 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.735724Z","caller":"traceutil/trace.go:171","msg":"trace[162685262] transaction","detail":"{read_only:false; response_revision:431; number_of_response:1; }","duration":"268.228314ms","start":"2025-02-13T19:37:48.467489Z","end":"2025-02-13T19:37:48.735717Z","steps":["trace[162685262] 'process raft request' (duration: 267.988674ms)"],"step_count":1} Feb 13 19:37:48.783489 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.783268Z","caller":"traceutil/trace.go:171","msg":"trace[957213554] transaction","detail":"{read_only:false; response_revision:433; number_of_response:1; }","duration":"181.629288ms","start":"2025-02-13T19:37:48.601632Z","end":"2025-02-13T19:37:48.783262Z","steps":["trace[957213554] 'process raft request' (duration: 181.553836ms)"],"step_count":1} Feb 13 19:37:48.977047 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.976637Z","caller":"traceutil/trace.go:171","msg":"trace[207022791] transaction","detail":"{read_only:false; response_revision:435; number_of_response:1; }","duration":"238.559128ms","start":"2025-02-13T19:37:48.738050Z","end":"2025-02-13T19:37:48.976610Z","steps":["trace[207022791] 'process raft request' (duration: 156.895581ms)","trace[207022791] 'compare' (duration: 81.48968ms)"],"step_count":2} Feb 13 19:37:48.977047 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.976677Z","caller":"traceutil/trace.go:171","msg":"trace[1034341607] transaction","detail":"{read_only:false; response_revision:436; number_of_response:1; }","duration":"238.279784ms","start":"2025-02-13T19:37:48.738391Z","end":"2025-02-13T19:37:48.976671Z","steps":["trace[1034341607] 'process raft request' (duration: 238.163676ms)"],"step_count":1} Feb 13 19:37:48.977047 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.976648Z","caller":"traceutil/trace.go:171","msg":"trace[1549311191] transaction","detail":"{read_only:false; response_revision:437; number_of_response:1; }","duration":"236.525079ms","start":"2025-02-13T19:37:48.740113Z","end":"2025-02-13T19:37:48.976639Z","steps":["trace[1549311191] 'process raft request' (duration: 236.48858ms)"],"step_count":1} Feb 13 19:37:48.991834 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:48.991615Z","caller":"traceutil/trace.go:171","msg":"trace[1882348168] transaction","detail":"{read_only:false; response_revision:438; number_of_response:1; }","duration":"204.387975ms","start":"2025-02-13T19:37:48.787216Z","end":"2025-02-13T19:37:48.991604Z","steps":["trace[1882348168] 'process raft request' (duration: 204.277568ms)"],"step_count":1} Feb 13 19:37:59.503416 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.502944Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"156.614844ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Feb 13 19:37:59.503416 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.503046Z","caller":"traceutil/trace.go:171","msg":"trace[2075272218] transaction","detail":"{read_only:false; response_revision:569; number_of_response:1; }","duration":"193.40761ms","start":"2025-02-13T19:37:59.309624Z","end":"2025-02-13T19:37:59.503032Z","steps":["trace[2075272218] 'process raft request' (duration: 36.65635ms)","trace[2075272218] 'compare' (duration: 156.492835ms)"],"step_count":2} Feb 13 19:37:59.503416 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.503071Z","caller":"traceutil/trace.go:171","msg":"trace[55888263] transaction","detail":"{read_only:false; response_revision:570; number_of_response:1; }","duration":"100.663717ms","start":"2025-02-13T19:37:59.402400Z","end":"2025-02-13T19:37:59.503064Z","steps":["trace[55888263] 'process raft request' (duration: 100.627088ms)"],"step_count":1} Feb 13 19:37:59.503416 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.503089Z","caller":"traceutil/trace.go:171","msg":"trace[718949589] linearizableReadLoop","detail":"{readStateIndex:586; appliedIndex:585; }","duration":"115.864453ms","start":"2025-02-13T19:37:59.387212Z","end":"2025-02-13T19:37:59.503076Z","steps":["trace[718949589] 'read index received' (duration: 28.423µs)","trace[718949589] 'applied index is now lower than readState.Index' (duration: 115.834467ms)"],"step_count":2} Feb 13 19:37:59.504092 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.503219Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.002663ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/calico-typha\" limit:1 ","response":"range_response_count:1 size:441"} Feb 13 19:37:59.504092 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.503246Z","caller":"traceutil/trace.go:171","msg":"trace[298725189] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/calico-typha; range_end:; response_count:1; response_revision:570; }","duration":"116.058076ms","start":"2025-02-13T19:37:59.387179Z","end":"2025-02-13T19:37:59.503237Z","steps":["trace[298725189] 'agreement among raft nodes before linearized reading' (duration: 115.936138ms)"],"step_count":1} Feb 13 19:37:59.710435 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.709987Z","caller":"traceutil/trace.go:171","msg":"trace[800936800] linearizableReadLoop","detail":"{readStateIndex:589; appliedIndex:588; }","duration":"161.389454ms","start":"2025-02-13T19:37:59.548567Z","end":"2025-02-13T19:37:59.709956Z","steps":["trace[800936800] 'read index received' (duration: 106.867729ms)","trace[800936800] 'applied index is now lower than readState.Index' (duration: 54.519411ms)"],"step_count":2} Feb 13 19:37:59.710435 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.710043Z","caller":"traceutil/trace.go:171","msg":"trace[87673593] transaction","detail":"{read_only:false; response_revision:572; number_of_response:1; }","duration":"202.170494ms","start":"2025-02-13T19:37:59.507853Z","end":"2025-02-13T19:37:59.710024Z","steps":["trace[87673593] 'process raft request' (duration: 147.573618ms)","trace[87673593] 'compare' (duration: 54.393716ms)"],"step_count":2} Feb 13 19:37:59.710435 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.710176Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"203.775235ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/calico-node-migration\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:37:59.710435 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.710205Z","caller":"traceutil/trace.go:171","msg":"trace[1711447171] range","detail":"{range_begin:/registry/clusterroles/calico-node-migration; range_end:; response_count:0; response_revision:572; }","duration":"203.836821ms","start":"2025-02-13T19:37:59.506360Z","end":"2025-02-13T19:37:59.710197Z","steps":["trace[1711447171] 'agreement among raft nodes before linearized reading' (duration: 203.706767ms)"],"step_count":1} Feb 13 19:37:59.778438 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777831Z","caller":"traceutil/trace.go:171","msg":"trace[2091669165] transaction","detail":"{read_only:false; response_revision:574; number_of_response:1; }","duration":"226.190511ms","start":"2025-02-13T19:37:59.551618Z","end":"2025-02-13T19:37:59.777809Z","steps":["trace[2091669165] 'process raft request' (duration: 226.085394ms)"],"step_count":1} Feb 13 19:37:59.778438 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777854Z","caller":"traceutil/trace.go:171","msg":"trace[1865818403] transaction","detail":"{read_only:false; response_revision:578; number_of_response:1; }","duration":"184.998989ms","start":"2025-02-13T19:37:59.592841Z","end":"2025-02-13T19:37:59.777840Z","steps":["trace[1865818403] 'process raft request' (duration: 184.973542ms)"],"step_count":1} Feb 13 19:37:59.778438 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777948Z","caller":"traceutil/trace.go:171","msg":"trace[766985738] transaction","detail":"{read_only:false; response_revision:573; number_of_response:1; }","duration":"226.497867ms","start":"2025-02-13T19:37:59.551442Z","end":"2025-02-13T19:37:59.777940Z","steps":["trace[766985738] 'process raft request' (duration: 226.180772ms)"],"step_count":1} Feb 13 19:37:59.778438 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777970Z","caller":"traceutil/trace.go:171","msg":"trace[383729542] transaction","detail":"{read_only:false; response_revision:577; number_of_response:1; }","duration":"225.221732ms","start":"2025-02-13T19:37:59.552742Z","end":"2025-02-13T19:37:59.777964Z","steps":["trace[383729542] 'process raft request' (duration: 225.04454ms)"],"step_count":1} Feb 13 19:37:59.778438 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777952Z","caller":"traceutil/trace.go:171","msg":"trace[842416106] transaction","detail":"{read_only:false; response_revision:576; number_of_response:1; }","duration":"226.182194ms","start":"2025-02-13T19:37:59.551761Z","end":"2025-02-13T19:37:59.777944Z","steps":["trace[842416106] 'process raft request' (duration: 226.004621ms)"],"step_count":1} Feb 13 19:37:59.778674 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.777855Z","caller":"traceutil/trace.go:171","msg":"trace[193564719] transaction","detail":"{read_only:false; response_revision:575; number_of_response:1; }","duration":"226.141709ms","start":"2025-02-13T19:37:59.551700Z","end":"2025-02-13T19:37:59.777841Z","steps":["trace[193564719] 'process raft request' (duration: 226.032203ms)"],"step_count":1} Feb 13 19:37:59.920383 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.919955Z","caller":"traceutil/trace.go:171","msg":"trace[705026086] linearizableReadLoop","detail":"{readStateIndex:596; appliedIndex:589; }","duration":"209.880633ms","start":"2025-02-13T19:37:59.710064Z","end":"2025-02-13T19:37:59.919944Z","steps":["trace[705026086] 'read index received' (duration: 67.570223ms)","trace[705026086] 'applied index is now lower than readState.Index' (duration: 142.309919ms)"],"step_count":2} Feb 13 19:37:59.920383 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.919979Z","caller":"traceutil/trace.go:171","msg":"trace[32124200] transaction","detail":"{read_only:false; response_revision:579; number_of_response:1; }","duration":"232.4406ms","start":"2025-02-13T19:37:59.687528Z","end":"2025-02-13T19:37:59.919968Z","steps":["trace[32124200] 'process raft request' (duration: 141.512934ms)","trace[32124200] 'compare' (duration: 90.808141ms)"],"step_count":2} Feb 13 19:37:59.920383 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.920004Z","caller":"traceutil/trace.go:171","msg":"trace[174095436] transaction","detail":"{read_only:false; response_revision:580; number_of_response:1; }","duration":"205.90851ms","start":"2025-02-13T19:37:59.714091Z","end":"2025-02-13T19:37:59.920000Z","steps":["trace[174095436] 'process raft request' (duration: 205.8289ms)"],"step_count":1} Feb 13 19:37:59.920383 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.920047Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"301.401804ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:37:59.920383 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.920050Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"369.52811ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/tigera-extension-apiserver-auth-access\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:37:59.920600 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.920062Z","caller":"traceutil/trace.go:171","msg":"trace[192923140] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:580; }","duration":"301.443692ms","start":"2025-02-13T19:37:59.618613Z","end":"2025-02-13T19:37:59.920057Z","steps":["trace[192923140] 'agreement among raft nodes before linearized reading' (duration: 301.410529ms)"],"step_count":1} Feb 13 19:37:59.920600 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.920073Z","caller":"traceutil/trace.go:171","msg":"trace[694728416] range","detail":"{range_begin:/registry/clusterroles/tigera-extension-apiserver-auth-access; range_end:; response_count:0; response_revision:580; }","duration":"369.573986ms","start":"2025-02-13T19:37:59.550492Z","end":"2025-02-13T19:37:59.920066Z","steps":["trace[694728416] 'agreement among raft nodes before linearized reading' (duration: 369.538419ms)"],"step_count":1} Feb 13 19:37:59.920600 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.920075Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-02-13T19:37:59.618600Z","time spent":"301.470602ms","remote":"10.0.0.62:58648","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} Feb 13 19:37:59.920600 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.920089Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2025-02-13T19:37:59.550483Z","time spent":"369.600866ms","remote":"10.0.0.62:58986","response type":"/etcdserverpb.KV/Range","request count":0,"request size":65,"response count":0,"response size":29,"request content":"key:\"/registry/clusterroles/tigera-extension-apiserver-auth-access\" limit:1 "} Feb 13 19:37:59.949228 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.948883Z","caller":"traceutil/trace.go:171","msg":"trace[1125863825] transaction","detail":"{read_only:false; response_revision:581; number_of_response:1; }","duration":"166.680093ms","start":"2025-02-13T19:37:59.782184Z","end":"2025-02-13T19:37:59.948864Z","steps":["trace[1125863825] 'process raft request' (duration: 166.527647ms)"],"step_count":1} Feb 13 19:37:59.949228 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.948992Z","caller":"traceutil/trace.go:171","msg":"trace[1368329603] transaction","detail":"{read_only:false; response_revision:583; number_of_response:1; }","duration":"164.500343ms","start":"2025-02-13T19:37:59.784484Z","end":"2025-02-13T19:37:59.948984Z","steps":["trace[1368329603] 'process raft request' (duration: 164.439348ms)"],"step_count":1} Feb 13 19:37:59.949228 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.949034Z","caller":"traceutil/trace.go:171","msg":"trace[1273922519] transaction","detail":"{read_only:false; response_revision:582; number_of_response:1; }","duration":"166.321671ms","start":"2025-02-13T19:37:59.782708Z","end":"2025-02-13T19:37:59.949030Z","steps":["trace[1273922519] 'process raft request' (duration: 166.118359ms)"],"step_count":1} Feb 13 19:37:59.949228 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.949055Z","caller":"traceutil/trace.go:171","msg":"trace[109033144] transaction","detail":"{read_only:false; response_revision:584; number_of_response:1; }","duration":"163.196796ms","start":"2025-02-13T19:37:59.785854Z","end":"2025-02-13T19:37:59.949051Z","steps":["trace[109033144] 'process raft request' (duration: 163.102459ms)"],"step_count":1} Feb 13 19:37:59.949228 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:37:59.949069Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"237.049889ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-node-migration\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:37:59.949383 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:37:59.949097Z","caller":"traceutil/trace.go:171","msg":"trace[279454894] range","detail":"{range_begin:/registry/clusterrolebindings/calico-node-migration; range_end:; response_count:0; response_revision:584; }","duration":"237.079485ms","start":"2025-02-13T19:37:59.712011Z","end":"2025-02-13T19:37:59.949091Z","steps":["trace[279454894] 'agreement among raft nodes before linearized reading' (duration: 237.041203ms)"],"step_count":1} Feb 13 19:38:00.161519 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.160862Z","caller":"traceutil/trace.go:171","msg":"trace[357526496] transaction","detail":"{read_only:false; response_revision:585; number_of_response:1; }","duration":"237.837743ms","start":"2025-02-13T19:37:59.922994Z","end":"2025-02-13T19:38:00.160832Z","steps":["trace[357526496] 'process raft request' (duration: 139.100382ms)","trace[357526496] 'compare' (duration: 98.514152ms)"],"step_count":2} Feb 13 19:38:00.161519 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.160931Z","caller":"traceutil/trace.go:171","msg":"trace[724722753] transaction","detail":"{read_only:false; response_revision:586; number_of_response:1; }","duration":"235.319417ms","start":"2025-02-13T19:37:59.925575Z","end":"2025-02-13T19:38:00.160894Z","steps":["trace[724722753] 'process raft request' (duration: 235.172952ms)"],"step_count":1} Feb 13 19:38:00.161519 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.161037Z","caller":"traceutil/trace.go:171","msg":"trace[357709160] transaction","detail":"{read_only:false; response_revision:587; number_of_response:1; }","duration":"222.820531ms","start":"2025-02-13T19:37:59.938210Z","end":"2025-02-13T19:38:00.161031Z","steps":["trace[357709160] 'process raft request' (duration: 222.64376ms)"],"step_count":1} Feb 13 19:38:00.161519 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.161041Z","caller":"traceutil/trace.go:171","msg":"trace[349525124] linearizableReadLoop","detail":"{readStateIndex:604; appliedIndex:601; }","duration":"212.040341ms","start":"2025-02-13T19:37:59.948983Z","end":"2025-02-13T19:38:00.161023Z","steps":["trace[349525124] 'read index received' (duration: 113.11116ms)","trace[349525124] 'applied index is now lower than readState.Index' (duration: 98.928299ms)"],"step_count":2} Feb 13 19:38:00.161519 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.161073Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"238.222535ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/tigera-extension-apiserver-auth-access\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:00.161754 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.161124Z","caller":"traceutil/trace.go:171","msg":"trace[2028116650] range","detail":"{range_begin:/registry/clusterrolebindings/tigera-extension-apiserver-auth-access; range_end:; response_count:0; response_revision:587; }","duration":"238.296663ms","start":"2025-02-13T19:37:59.922817Z","end":"2025-02-13T19:38:00.161114Z","steps":["trace[2028116650] 'agreement among raft nodes before linearized reading' (duration: 238.212595ms)"],"step_count":1} Feb 13 19:38:00.161754 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.161124Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"240.390002ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:38:00.161754 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.161150Z","caller":"traceutil/trace.go:171","msg":"trace[75718359] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:587; }","duration":"240.44299ms","start":"2025-02-13T19:37:59.920700Z","end":"2025-02-13T19:38:00.161143Z","steps":["trace[75718359] 'agreement among raft nodes before linearized reading' (duration: 240.394469ms)"],"step_count":1} Feb 13 19:38:00.164979 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.164622Z","caller":"traceutil/trace.go:171","msg":"trace[1248010858] transaction","detail":"{read_only:false; response_revision:588; number_of_response:1; }","duration":"212.474174ms","start":"2025-02-13T19:37:59.952139Z","end":"2025-02-13T19:38:00.164613Z","steps":["trace[1248010858] 'process raft request' (duration: 212.372644ms)"],"step_count":1} Feb 13 19:38:00.164979 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.164711Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.791299ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/calico-system/calico-typha-8457d7f99-qgzmt.1823dbbb8899a7f9\" limit:1 ","response":"range_response_count:1 size:842"} Feb 13 19:38:00.164979 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.164743Z","caller":"traceutil/trace.go:171","msg":"trace[1122599544] range","detail":"{range_begin:/registry/events/calico-system/calico-typha-8457d7f99-qgzmt.1823dbbb8899a7f9; range_end:; response_count:1; response_revision:589; }","duration":"119.860078ms","start":"2025-02-13T19:38:00.044871Z","end":"2025-02-13T19:38:00.164731Z","steps":["trace[1122599544] 'agreement among raft nodes before linearized reading' (duration: 119.778615ms)"],"step_count":1} Feb 13 19:38:00.165163 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.164771Z","caller":"traceutil/trace.go:171","msg":"trace[1926383903] transaction","detail":"{read_only:false; response_revision:589; number_of_response:1; }","duration":"110.563433ms","start":"2025-02-13T19:38:00.054198Z","end":"2025-02-13T19:38:00.164762Z","steps":["trace[1926383903] 'process raft request' (duration: 110.376491ms)"],"step_count":1} Feb 13 19:38:00.165163 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.164743Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"211.456416ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/replicasets/calico-apiserver/calico-apiserver-7dc54544cd\" limit:1 ","response":"range_response_count:1 size:4268"} Feb 13 19:38:00.165163 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.164815Z","caller":"traceutil/trace.go:171","msg":"trace[559418222] range","detail":"{range_begin:/registry/replicasets/calico-apiserver/calico-apiserver-7dc54544cd; range_end:; response_count:1; response_revision:589; }","duration":"211.54457ms","start":"2025-02-13T19:37:59.953263Z","end":"2025-02-13T19:38:00.164808Z","steps":["trace[559418222] 'agreement among raft nodes before linearized reading' (duration: 211.407662ms)"],"step_count":1} Feb 13 19:38:00.436490 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.436086Z","caller":"traceutil/trace.go:171","msg":"trace[1658714500] linearizableReadLoop","detail":"{readStateIndex:634; appliedIndex:632; }","duration":"209.433494ms","start":"2025-02-13T19:38:00.226636Z","end":"2025-02-13T19:38:00.436070Z","steps":["trace[1658714500] 'read index received' (duration: 11.337245ms)","trace[1658714500] 'applied index is now lower than readState.Index' (duration: 198.095407ms)"],"step_count":2} Feb 13 19:38:00.436633 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.436169Z","caller":"traceutil/trace.go:171","msg":"trace[1045209] transaction","detail":"{read_only:false; response_revision:618; number_of_response:1; }","duration":"209.003486ms","start":"2025-02-13T19:38:00.227140Z","end":"2025-02-13T19:38:00.436143Z","steps":["trace[1045209] 'process raft request' (duration: 208.905523ms)"],"step_count":1} Feb 13 19:38:00.436633 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.436182Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"209.528552ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/tigera-uisettings-passthrough\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:00.436633 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.436206Z","caller":"traceutil/trace.go:171","msg":"trace[1014749688] range","detail":"{range_begin:/registry/clusterroles/tigera-uisettings-passthrough; range_end:; response_count:0; response_revision:618; }","duration":"209.573727ms","start":"2025-02-13T19:38:00.226625Z","end":"2025-02-13T19:38:00.436199Z","steps":["trace[1014749688] 'agreement among raft nodes before linearized reading' (duration: 209.523263ms)"],"step_count":1} Feb 13 19:38:00.436633 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.436214Z","caller":"traceutil/trace.go:171","msg":"trace[1384561864] transaction","detail":"{read_only:false; response_revision:616; number_of_response:1; }","duration":"210.048377ms","start":"2025-02-13T19:38:00.226154Z","end":"2025-02-13T19:38:00.436203Z","steps":["trace[1384561864] 'process raft request' (duration: 119.600219ms)","trace[1384561864] 'compare' (duration: 90.14557ms)"],"step_count":2} Feb 13 19:38:00.436633 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.436325Z","caller":"traceutil/trace.go:171","msg":"trace[1148846018] transaction","detail":"{read_only:false; response_revision:617; number_of_response:1; }","duration":"209.961153ms","start":"2025-02-13T19:38:00.226168Z","end":"2025-02-13T19:38:00.436129Z","steps":["trace[1148846018] 'process raft request' (duration: 209.838232ms)"],"step_count":1} Feb 13 19:38:00.466309 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.466018Z","caller":"traceutil/trace.go:171","msg":"trace[465433341] transaction","detail":"{read_only:false; response_revision:619; number_of_response:1; }","duration":"224.763329ms","start":"2025-02-13T19:38:00.241246Z","end":"2025-02-13T19:38:00.466010Z","steps":["trace[465433341] 'process raft request' (duration: 224.714618ms)"],"step_count":1} Feb 13 19:38:00.466309 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.466088Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"237.364256ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/deployments/calico-system/calico-kube-controllers\" limit:1 ","response":"range_response_count:1 size:4901"} Feb 13 19:38:00.466309 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.466102Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"171.376178ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/calico-node\" limit:1 ","response":"range_response_count:1 size:525"} Feb 13 19:38:00.466309 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.466120Z","caller":"traceutil/trace.go:171","msg":"trace[1710079053] range","detail":"{range_begin:/registry/deployments/calico-system/calico-kube-controllers; range_end:; response_count:1; response_revision:619; }","duration":"237.407928ms","start":"2025-02-13T19:38:00.228705Z","end":"2025-02-13T19:38:00.466113Z","steps":["trace[1710079053] 'agreement among raft nodes before linearized reading' (duration: 237.322027ms)"],"step_count":1} Feb 13 19:38:00.466309 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.466128Z","caller":"traceutil/trace.go:171","msg":"trace[896389548] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/calico-node; range_end:; response_count:1; response_revision:619; }","duration":"171.438406ms","start":"2025-02-13T19:38:00.294682Z","end":"2025-02-13T19:38:00.466121Z","steps":["trace[896389548] 'agreement among raft nodes before linearized reading' (duration: 171.355961ms)"],"step_count":1} Feb 13 19:38:00.767909 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.767400Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"217.286859ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Feb 13 19:38:00.767909 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767498Z","caller":"traceutil/trace.go:171","msg":"trace[2013781101] transaction","detail":"{read_only:false; response_revision:620; number_of_response:1; }","duration":"296.958494ms","start":"2025-02-13T19:38:00.470523Z","end":"2025-02-13T19:38:00.767481Z","steps":["trace[2013781101] 'process raft request' (duration: 79.540668ms)","trace[2013781101] 'compare' (duration: 217.215766ms)"],"step_count":2} Feb 13 19:38:00.767909 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767539Z","caller":"traceutil/trace.go:171","msg":"trace[1847741026] transaction","detail":"{read_only:false; response_revision:621; number_of_response:1; }","duration":"274.128424ms","start":"2025-02-13T19:38:00.493401Z","end":"2025-02-13T19:38:00.767529Z","steps":["trace[1847741026] 'process raft request' (duration: 274.074473ms)"],"step_count":1} Feb 13 19:38:00.767909 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767588Z","caller":"traceutil/trace.go:171","msg":"trace[1751037954] linearizableReadLoop","detail":"{readStateIndex:637; appliedIndex:636; }","duration":"296.699358ms","start":"2025-02-13T19:38:00.470882Z","end":"2025-02-13T19:38:00.767581Z","steps":["trace[1751037954] 'read index received' (duration: 79.1952ms)","trace[1751037954] 'applied index is now lower than readState.Index' (duration: 217.503617ms)"],"step_count":2} Feb 13 19:38:00.768581 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.767632Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"296.74339ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/tigera-network-admin\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:00.768581 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767676Z","caller":"traceutil/trace.go:171","msg":"trace[1675450545] range","detail":"{range_begin:/registry/clusterroles/tigera-network-admin; range_end:; response_count:0; response_revision:622; }","duration":"296.798404ms","start":"2025-02-13T19:38:00.470871Z","end":"2025-02-13T19:38:00.767669Z","steps":["trace[1675450545] 'agreement among raft nodes before linearized reading' (duration: 296.740716ms)"],"step_count":1} Feb 13 19:38:00.768581 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.767694Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"151.399541ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/10.0.0.62\" limit:1 ","response":"range_response_count:1 size:125"} Feb 13 19:38:00.768581 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767718Z","caller":"traceutil/trace.go:171","msg":"trace[1371139746] range","detail":"{range_begin:/registry/masterleases/10.0.0.62; range_end:; response_count:1; response_revision:622; }","duration":"151.445217ms","start":"2025-02-13T19:38:00.616268Z","end":"2025-02-13T19:38:00.767713Z","steps":["trace[1371139746] 'agreement among raft nodes before linearized reading' (duration: 151.356361ms)"],"step_count":1} Feb 13 19:38:00.768581 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:00.767773Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"149.249938ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:38:00.768705 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:00.767809Z","caller":"traceutil/trace.go:171","msg":"trace[2084259196] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:622; }","duration":"149.285415ms","start":"2025-02-13T19:38:00.618517Z","end":"2025-02-13T19:38:00.767803Z","steps":["trace[2084259196] 'agreement among raft nodes before linearized reading' (duration: 149.236093ms)"],"step_count":1} Feb 13 19:38:01.012309 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:01.011953Z","caller":"traceutil/trace.go:171","msg":"trace[166704245] transaction","detail":"{read_only:false; response_revision:626; number_of_response:1; }","duration":"150.654382ms","start":"2025-02-13T19:38:00.861284Z","end":"2025-02-13T19:38:01.011938Z","steps":["trace[166704245] 'process raft request' (duration: 57.144542ms)","trace[166704245] 'compare' (duration: 93.438236ms)"],"step_count":2} Feb 13 19:38:08.698890 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:08.698548Z","caller":"traceutil/trace.go:171","msg":"trace[1611745874] transaction","detail":"{read_only:false; response_revision:671; number_of_response:1; }","duration":"105.601243ms","start":"2025-02-13T19:38:08.592922Z","end":"2025-02-13T19:38:08.698523Z","steps":["trace[1611745874] 'process raft request' (duration: 79.374435ms)","trace[1611745874] 'compare' (duration: 26.09519ms)"],"step_count":2} Feb 13 19:38:10.368261 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:10.367965Z","caller":"traceutil/trace.go:171","msg":"trace[1765255211] transaction","detail":"{read_only:false; response_revision:676; number_of_response:1; }","duration":"141.149181ms","start":"2025-02-13T19:38:10.226797Z","end":"2025-02-13T19:38:10.367947Z","steps":["trace[1765255211] 'process raft request' (duration: 141.044497ms)"],"step_count":1} Feb 13 19:38:12.124609 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.124216Z","caller":"traceutil/trace.go:171","msg":"trace[234763901] transaction","detail":"{read_only:false; response_revision:685; number_of_response:1; }","duration":"107.509827ms","start":"2025-02-13T19:38:12.016686Z","end":"2025-02-13T19:38:12.124196Z","steps":["trace[234763901] 'process raft request' (duration: 60.535183ms)","trace[234763901] 'compare' (duration: 46.8228ms)"],"step_count":2} Feb 13 19:38:12.300541 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.299434Z","caller":"traceutil/trace.go:171","msg":"trace[447355] transaction","detail":"{read_only:false; response_revision:687; number_of_response:1; }","duration":"171.495332ms","start":"2025-02-13T19:38:12.127922Z","end":"2025-02-13T19:38:12.299417Z","steps":["trace[447355] 'process raft request' (duration: 97.507971ms)","trace[447355] 'compare' (duration: 73.897839ms)"],"step_count":2} Feb 13 19:38:12.300541 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.299586Z","caller":"traceutil/trace.go:171","msg":"trace[535173879] transaction","detail":"{read_only:false; response_revision:688; number_of_response:1; }","duration":"167.49152ms","start":"2025-02-13T19:38:12.132083Z","end":"2025-02-13T19:38:12.299575Z","steps":["trace[535173879] 'process raft request' (duration: 167.417777ms)"],"step_count":1} Feb 13 19:38:12.960846 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:12.960542Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"163.933066ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Feb 13 19:38:12.960846 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.960618Z","caller":"traceutil/trace.go:171","msg":"trace[1571395348] transaction","detail":"{read_only:false; response_revision:701; number_of_response:1; }","duration":"182.058052ms","start":"2025-02-13T19:38:12.778548Z","end":"2025-02-13T19:38:12.960606Z","steps":["trace[1571395348] 'process raft request' (duration: 18.01819ms)","trace[1571395348] 'compare' (duration: 163.819857ms)"],"step_count":2} Feb 13 19:38:12.991257 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.990932Z","caller":"traceutil/trace.go:171","msg":"trace[1056783361] transaction","detail":"{read_only:false; response_revision:702; number_of_response:1; }","duration":"211.694212ms","start":"2025-02-13T19:38:12.779214Z","end":"2025-02-13T19:38:12.990908Z","steps":["trace[1056783361] 'process raft request' (duration: 211.578187ms)"],"step_count":1} Feb 13 19:38:12.991257 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.990956Z","caller":"traceutil/trace.go:171","msg":"trace[1815440762] linearizableReadLoop","detail":"{readStateIndex:724; appliedIndex:722; }","duration":"211.430011ms","start":"2025-02-13T19:38:12.779515Z","end":"2025-02-13T19:38:12.990945Z","steps":["trace[1815440762] 'read index received' (duration: 17.055087ms)","trace[1815440762] 'applied index is now lower than readState.Index' (duration: 194.374453ms)"],"step_count":2} Feb 13 19:38:12.991257 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.991008Z","caller":"traceutil/trace.go:171","msg":"trace[214164052] transaction","detail":"{read_only:false; response_revision:703; number_of_response:1; }","duration":"211.464388ms","start":"2025-02-13T19:38:12.779539Z","end":"2025-02-13T19:38:12.991003Z","steps":["trace[214164052] 'process raft request' (duration: 211.324568ms)"],"step_count":1} Feb 13 19:38:12.991580 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.991031Z","caller":"traceutil/trace.go:171","msg":"trace[1427376925] transaction","detail":"{read_only:false; response_revision:705; number_of_response:1; }","duration":"207.299303ms","start":"2025-02-13T19:38:12.783723Z","end":"2025-02-13T19:38:12.991022Z","steps":["trace[1427376925] 'process raft request' (duration: 207.187897ms)"],"step_count":1} Feb 13 19:38:12.991580 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:12.991095Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"211.564801ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/resourcequotas\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:12.991580 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.991137Z","caller":"traceutil/trace.go:171","msg":"trace[848111252] transaction","detail":"{read_only:false; response_revision:704; number_of_response:1; }","duration":"211.587596ms","start":"2025-02-13T19:38:12.779542Z","end":"2025-02-13T19:38:12.991130Z","steps":["trace[848111252] 'process raft request' (duration: 211.339336ms)"],"step_count":1} Feb 13 19:38:12.991580 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:12.991113Z","caller":"traceutil/trace.go:171","msg":"trace[1822575057] range","detail":"{range_begin:/registry/resourcequotas; range_end:; response_count:0; response_revision:705; }","duration":"211.602785ms","start":"2025-02-13T19:38:12.779505Z","end":"2025-02-13T19:38:12.991108Z","steps":["trace[1822575057] 'agreement among raft nodes before linearized reading' (duration: 211.563309ms)"],"step_count":1} Feb 13 19:38:13.019953 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.019687Z","caller":"traceutil/trace.go:171","msg":"trace[814424232] transaction","detail":"{read_only:false; response_revision:706; number_of_response:1; }","duration":"145.711625ms","start":"2025-02-13T19:38:12.873967Z","end":"2025-02-13T19:38:13.019678Z","steps":["trace[814424232] 'process raft request' (duration: 145.623484ms)"],"step_count":1} Feb 13 19:38:13.019953 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:13.019718Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.43263ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/tigera-operator/operator-lock\" limit:1 ","response":"range_response_count:1 size:480"} Feb 13 19:38:13.019953 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.019744Z","caller":"traceutil/trace.go:171","msg":"trace[283798210] range","detail":"{range_begin:/registry/leases/tigera-operator/operator-lock; range_end:; response_count:1; response_revision:706; }","duration":"117.472727ms","start":"2025-02-13T19:38:12.902264Z","end":"2025-02-13T19:38:13.019736Z","steps":["trace[283798210] 'agreement among raft nodes before linearized reading' (duration: 117.390458ms)"],"step_count":1} Feb 13 19:38:13.157450 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.156765Z","caller":"traceutil/trace.go:171","msg":"trace[1469252792] transaction","detail":"{read_only:false; response_revision:707; number_of_response:1; }","duration":"163.98235ms","start":"2025-02-13T19:38:12.992765Z","end":"2025-02-13T19:38:13.156748Z","steps":["trace[1469252792] 'process raft request' (duration: 102.141572ms)","trace[1469252792] 'compare' (duration: 61.710256ms)"],"step_count":2} Feb 13 19:38:13.157450 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.156788Z","caller":"traceutil/trace.go:171","msg":"trace[264472066] transaction","detail":"{read_only:false; response_revision:708; number_of_response:1; }","duration":"160.645375ms","start":"2025-02-13T19:38:12.996131Z","end":"2025-02-13T19:38:13.156776Z","steps":["trace[264472066] 'process raft request' (duration: 160.580089ms)"],"step_count":1} Feb 13 19:38:13.157450 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.156851Z","caller":"traceutil/trace.go:171","msg":"trace[1452382338] transaction","detail":"{read_only:false; response_revision:709; number_of_response:1; }","duration":"160.42057ms","start":"2025-02-13T19:38:12.996425Z","end":"2025-02-13T19:38:13.156846Z","steps":["trace[1452382338] 'process raft request' (duration: 160.310707ms)"],"step_count":1} Feb 13 19:38:13.157450 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.156868Z","caller":"traceutil/trace.go:171","msg":"trace[808425080] transaction","detail":"{read_only:false; response_revision:711; number_of_response:1; }","duration":"160.229441ms","start":"2025-02-13T19:38:12.996631Z","end":"2025-02-13T19:38:13.156860Z","steps":["trace[808425080] 'process raft request' (duration: 160.184173ms)"],"step_count":1} Feb 13 19:38:13.157450 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.156908Z","caller":"traceutil/trace.go:171","msg":"trace[134101865] transaction","detail":"{read_only:false; response_revision:710; number_of_response:1; }","duration":"160.30668ms","start":"2025-02-13T19:38:12.996593Z","end":"2025-02-13T19:38:13.156899Z","steps":["trace[134101865] 'process raft request' (duration: 160.176968ms)"],"step_count":1} Feb 13 19:38:13.158137 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157028Z","caller":"traceutil/trace.go:171","msg":"trace[2074740740] transaction","detail":"{read_only:false; response_revision:712; number_of_response:1; }","duration":"159.994445ms","start":"2025-02-13T19:38:12.997026Z","end":"2025-02-13T19:38:13.157020Z","steps":["trace[2074740740] 'process raft request' (duration: 159.813775ms)"],"step_count":1} Feb 13 19:38:13.158137 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157194Z","caller":"traceutil/trace.go:171","msg":"trace[1888018124] linearizableReadLoop","detail":"{readStateIndex:737; appliedIndex:728; }","duration":"117.72834ms","start":"2025-02-13T19:38:13.039458Z","end":"2025-02-13T19:38:13.157186Z","steps":["trace[1888018124] 'read index received' (duration: 55.457892ms)","trace[1888018124] 'applied index is now lower than readState.Index' (duration: 62.269756ms)"],"step_count":2} Feb 13 19:38:13.158137 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157205Z","caller":"traceutil/trace.go:171","msg":"trace[1724991603] transaction","detail":"{read_only:false; response_revision:713; number_of_response:1; }","duration":"160.016618ms","start":"2025-02-13T19:38:12.997117Z","end":"2025-02-13T19:38:13.157133Z","steps":["trace[1724991603] 'process raft request' (duration: 159.819628ms)"],"step_count":1} Feb 13 19:38:13.158137 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157276Z","caller":"traceutil/trace.go:171","msg":"trace[2044352543] transaction","detail":"{read_only:false; response_revision:715; number_of_response:1; }","duration":"135.630075ms","start":"2025-02-13T19:38:13.021640Z","end":"2025-02-13T19:38:13.157270Z","steps":["trace[2044352543] 'process raft request' (duration: 135.45654ms)"],"step_count":1} Feb 13 19:38:13.158137 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:13.157329Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.859283ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/10.0.0.69\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:13.158317 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157333Z","caller":"traceutil/trace.go:171","msg":"trace[1785877646] transaction","detail":"{read_only:false; response_revision:714; number_of_response:1; }","duration":"160.086323ms","start":"2025-02-13T19:38:12.997241Z","end":"2025-02-13T19:38:13.157327Z","steps":["trace[1785877646] 'process raft request' (duration: 159.828215ms)"],"step_count":1} Feb 13 19:38:13.158317 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:13.157351Z","caller":"traceutil/trace.go:171","msg":"trace[818144240] range","detail":"{range_begin:/registry/csinodes/10.0.0.69; range_end:; response_count:0; response_revision:715; }","duration":"117.905602ms","start":"2025-02-13T19:38:13.039438Z","end":"2025-02-13T19:38:13.157344Z","steps":["trace[818144240] 'agreement among raft nodes before linearized reading' (duration: 117.863962ms)"],"step_count":1} Feb 13 19:38:18.558257 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:18.557959Z","caller":"traceutil/trace.go:171","msg":"trace[283645125] transaction","detail":"{read_only:false; response_revision:838; number_of_response:1; }","duration":"100.603001ms","start":"2025-02-13T19:38:18.457331Z","end":"2025-02-13T19:38:18.557934Z","steps":["trace[283645125] 'process raft request' (duration: 74.586908ms)","trace[283645125] 'compare' (duration: 25.831117ms)"],"step_count":2} Feb 13 19:38:23.217833 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.217547Z","caller":"traceutil/trace.go:171","msg":"trace[2024606205] linearizableReadLoop","detail":"{readStateIndex:966; appliedIndex:965; }","duration":"122.491708ms","start":"2025-02-13T19:38:23.095041Z","end":"2025-02-13T19:38:23.217533Z","steps":["trace[2024606205] 'read index received' (duration: 91.128428ms)","trace[2024606205] 'applied index is now lower than readState.Index' (duration: 31.362829ms)"],"step_count":2} Feb 13 19:38:23.217833 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.217579Z","caller":"traceutil/trace.go:171","msg":"trace[1331959203] transaction","detail":"{read_only:false; response_revision:940; number_of_response:1; }","duration":"136.224298ms","start":"2025-02-13T19:38:23.081341Z","end":"2025-02-13T19:38:23.217566Z","steps":["trace[1331959203] 'process raft request' (duration: 104.832824ms)","trace[1331959203] 'compare' (duration: 31.301481ms)"],"step_count":2} Feb 13 19:38:23.217833 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:23.217653Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"135.692667ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/services/endpoints/calico-system/calico-typha\" limit:1 ","response":"range_response_count:1 size:658"} Feb 13 19:38:23.217833 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.217673Z","caller":"traceutil/trace.go:171","msg":"trace[1076394906] range","detail":"{range_begin:/registry/services/endpoints/calico-system/calico-typha; range_end:; response_count:1; response_revision:940; }","duration":"135.730009ms","start":"2025-02-13T19:38:23.081937Z","end":"2025-02-13T19:38:23.217667Z","steps":["trace[1076394906] 'agreement among raft nodes before linearized reading' (duration: 135.661989ms)"],"step_count":1} Feb 13 19:38:23.225033 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.224922Z","caller":"traceutil/trace.go:171","msg":"trace[1915686072] transaction","detail":"{read_only:false; response_revision:941; number_of_response:1; }","duration":"124.932282ms","start":"2025-02-13T19:38:23.099983Z","end":"2025-02-13T19:38:23.224915Z","steps":["trace[1915686072] 'process raft request' (duration: 124.869151ms)"],"step_count":1} Feb 13 19:38:23.225275 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:23.225004Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"127.861502ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/ipamhandles/wireguard-tunnel-addr-localhost\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:23.225275 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.225038Z","caller":"traceutil/trace.go:171","msg":"trace[1044223255] range","detail":"{range_begin:/registry/crd.projectcalico.org/ipamhandles/wireguard-tunnel-addr-localhost; range_end:; response_count:0; response_revision:942; }","duration":"127.901379ms","start":"2025-02-13T19:38:23.097127Z","end":"2025-02-13T19:38:23.225028Z","steps":["trace[1044223255] 'agreement among raft nodes before linearized reading' (duration: 127.859739ms)"],"step_count":1} Feb 13 19:38:23.532242 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:23.531971Z","caller":"traceutil/trace.go:171","msg":"trace[346392571] transaction","detail":"{read_only:false; response_revision:953; number_of_response:1; }","duration":"108.083871ms","start":"2025-02-13T19:38:23.423867Z","end":"2025-02-13T19:38:23.531951Z","steps":["trace[346392571] 'process raft request' (duration: 65.179155ms)","trace[346392571] 'compare' (duration: 42.785287ms)"],"step_count":2} Feb 13 19:38:24.708189 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.707927Z","caller":"traceutil/trace.go:171","msg":"trace[901129569] transaction","detail":"{read_only:false; response_revision:979; number_of_response:1; }","duration":"117.431613ms","start":"2025-02-13T19:38:24.590475Z","end":"2025-02-13T19:38:24.707907Z","steps":["trace[901129569] 'process raft request' (duration: 96.121397ms)","trace[901129569] 'compare' (duration: 21.229863ms)"],"step_count":2} Feb 13 19:38:24.726336 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.726039Z","caller":"traceutil/trace.go:171","msg":"trace[1421465422] transaction","detail":"{read_only:false; response_revision:980; number_of_response:1; }","duration":"134.682995ms","start":"2025-02-13T19:38:24.591340Z","end":"2025-02-13T19:38:24.726023Z","steps":["trace[1421465422] 'process raft request' (duration: 134.560511ms)"],"step_count":1} Feb 13 19:38:24.726336 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.726086Z","caller":"traceutil/trace.go:171","msg":"trace[1778565797] linearizableReadLoop","detail":"{readStateIndex:1008; appliedIndex:1004; }","duration":"106.847087ms","start":"2025-02-13T19:38:24.619233Z","end":"2025-02-13T19:38:24.726080Z","steps":["trace[1778565797] 'read index received' (duration: 67.446379ms)","trace[1778565797] 'applied index is now lower than readState.Index' (duration: 39.400167ms)"],"step_count":2} Feb 13 19:38:24.726336 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.726039Z","caller":"traceutil/trace.go:171","msg":"trace[1072895895] transaction","detail":"{read_only:false; response_revision:981; number_of_response:1; }","duration":"133.808999ms","start":"2025-02-13T19:38:24.592219Z","end":"2025-02-13T19:38:24.726028Z","steps":["trace[1072895895] 'process raft request' (duration: 133.749626ms)"],"step_count":1} Feb 13 19:38:24.726336 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.726122Z","caller":"traceutil/trace.go:171","msg":"trace[1937951375] transaction","detail":"{read_only:false; response_revision:982; number_of_response:1; }","duration":"133.594708ms","start":"2025-02-13T19:38:24.592523Z","end":"2025-02-13T19:38:24.726118Z","steps":["trace[1937951375] 'process raft request' (duration: 133.472173ms)"],"step_count":1} Feb 13 19:38:24.726336 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:24.726148Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"106.906661ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:38:24.726560 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:24.726164Z","caller":"traceutil/trace.go:171","msg":"trace[249599614] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:982; }","duration":"106.948431ms","start":"2025-02-13T19:38:24.619211Z","end":"2025-02-13T19:38:24.726160Z","steps":["trace[249599614] 'agreement among raft nodes before linearized reading' (duration: 106.914697ms)"],"step_count":1} Feb 13 19:38:27.734430 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:27.733957Z","caller":"traceutil/trace.go:171","msg":"trace[1734825984] linearizableReadLoop","detail":"{readStateIndex:1043; appliedIndex:1042; }","duration":"115.489998ms","start":"2025-02-13T19:38:27.618449Z","end":"2025-02-13T19:38:27.733939Z","steps":["trace[1734825984] 'read index received' (duration: 100.387846ms)","trace[1734825984] 'applied index is now lower than readState.Index' (duration: 15.10087ms)"],"step_count":2} Feb 13 19:38:27.734430 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:27.734044Z","caller":"traceutil/trace.go:171","msg":"trace[357966499] transaction","detail":"{read_only:false; response_revision:1012; number_of_response:1; }","duration":"170.101368ms","start":"2025-02-13T19:38:27.563924Z","end":"2025-02-13T19:38:27.734025Z","steps":["trace[357966499] 'process raft request' (duration: 154.883524ms)","trace[357966499] 'compare' (duration: 15.034052ms)"],"step_count":2} Feb 13 19:38:27.734430 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:27.734076Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"115.617341ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:38:27.734430 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:27.734142Z","caller":"traceutil/trace.go:171","msg":"trace[1865961030] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1012; }","duration":"115.721259ms","start":"2025-02-13T19:38:27.618415Z","end":"2025-02-13T19:38:27.734136Z","steps":["trace[1865961030] 'agreement among raft nodes before linearized reading' (duration: 115.623533ms)"],"step_count":1} Feb 13 19:38:27.903779 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:27.901201Z","caller":"traceutil/trace.go:171","msg":"trace[403582552] transaction","detail":"{read_only:false; response_revision:1014; number_of_response:1; }","duration":"162.662045ms","start":"2025-02-13T19:38:27.738506Z","end":"2025-02-13T19:38:27.901168Z","steps":["trace[403582552] 'process raft request' (duration: 125.576397ms)","trace[403582552] 'compare' (duration: 36.797416ms)"],"step_count":2} Feb 13 19:38:28.206016 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:28.205720Z","caller":"traceutil/trace.go:171","msg":"trace[500546070] transaction","detail":"{read_only:false; response_revision:1015; number_of_response:1; }","duration":"129.936723ms","start":"2025-02-13T19:38:28.075761Z","end":"2025-02-13T19:38:28.205698Z","steps":["trace[500546070] 'process raft request' (duration: 76.859774ms)","trace[500546070] 'compare' (duration: 52.996996ms)"],"step_count":2} Feb 13 19:38:29.676985 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:29.676673Z","caller":"traceutil/trace.go:171","msg":"trace[703509655] transaction","detail":"{read_only:false; response_revision:1022; number_of_response:1; }","duration":"100.98044ms","start":"2025-02-13T19:38:29.575663Z","end":"2025-02-13T19:38:29.676644Z","steps":["trace[703509655] 'process raft request' (duration: 46.513365ms)","trace[703509655] 'compare' (duration: 54.336926ms)"],"step_count":2} Feb 13 19:38:36.777258 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:36.776903Z","caller":"traceutil/trace.go:171","msg":"trace[415775812] linearizableReadLoop","detail":"{readStateIndex:1231; appliedIndex:1230; }","duration":"146.706652ms","start":"2025-02-13T19:38:36.630177Z","end":"2025-02-13T19:38:36.776884Z","steps":["trace[415775812] 'read index received' (duration: 60.492603ms)","trace[415775812] 'applied index is now lower than readState.Index' (duration: 86.213288ms)"],"step_count":2} Feb 13 19:38:36.777926 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:36.777000Z","caller":"traceutil/trace.go:171","msg":"trace[1741888893] transaction","detail":"{read_only:false; response_revision:1120; number_of_response:1; }","duration":"151.106882ms","start":"2025-02-13T19:38:36.625876Z","end":"2025-02-13T19:38:36.776983Z","steps":["trace[1741888893] 'process raft request' (duration: 64.831515ms)","trace[1741888893] 'compare' (duration: 86.075185ms)"],"step_count":2} Feb 13 19:38:36.777926 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:36.777015Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"146.817876ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/tigera-uisettings-passthrough\" limit:1 ","response":"range_response_count:0 size:5"} Feb 13 19:38:36.777926 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:36.777087Z","caller":"traceutil/trace.go:171","msg":"trace[651615336] range","detail":"{range_begin:/registry/clusterrolebindings/tigera-uisettings-passthrough; range_end:; response_count:0; response_revision:1120; }","duration":"146.91489ms","start":"2025-02-13T19:38:36.630162Z","end":"2025-02-13T19:38:36.777077Z","steps":["trace[651615336] 'agreement among raft nodes before linearized reading' (duration: 146.815951ms)"],"step_count":1} Feb 13 19:38:36.777926 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:36.777094Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.128805ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/clusterinformations/default\" limit:1 ","response":"range_response_count:1 size:886"} Feb 13 19:38:36.778064 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:36.777113Z","caller":"traceutil/trace.go:171","msg":"trace[690024602] range","detail":"{range_begin:/registry/crd.projectcalico.org/clusterinformations/default; range_end:; response_count:1; response_revision:1120; }","duration":"117.168952ms","start":"2025-02-13T19:38:36.659937Z","end":"2025-02-13T19:38:36.777106Z","steps":["trace[690024602] 'agreement among raft nodes before linearized reading' (duration: 117.095221ms)"],"step_count":1} Feb 13 19:38:39.517613 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:39.517265Z","caller":"traceutil/trace.go:171","msg":"trace[1869793007] transaction","detail":"{read_only:false; response_revision:1133; number_of_response:1; }","duration":"124.900065ms","start":"2025-02-13T19:38:39.392341Z","end":"2025-02-13T19:38:39.517241Z","steps":["trace[1869793007] 'process raft request' (duration: 91.280036ms)","trace[1869793007] 'compare' (duration: 33.501143ms)"],"step_count":2} Feb 13 19:38:43.499778 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:43.499456Z","caller":"traceutil/trace.go:171","msg":"trace[678684982] transaction","detail":"{read_only:false; response_revision:1183; number_of_response:1; }","duration":"113.763548ms","start":"2025-02-13T19:38:43.385675Z","end":"2025-02-13T19:38:43.499438Z","steps":["trace[678684982] 'process raft request' (duration: 113.677405ms)"],"step_count":1} Feb 13 19:38:43.654615 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:43.654291Z","caller":"traceutil/trace.go:171","msg":"trace[1813551461] transaction","detail":"{read_only:false; response_revision:1184; number_of_response:1; }","duration":"105.707881ms","start":"2025-02-13T19:38:43.548564Z","end":"2025-02-13T19:38:43.654272Z","steps":["trace[1813551461] 'process raft request' (duration: 105.538618ms)"],"step_count":1} Feb 13 19:38:43.786012 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:43.785618Z","caller":"traceutil/trace.go:171","msg":"trace[1252079459] linearizableReadLoop","detail":"{readStateIndex:1301; appliedIndex:1300; }","duration":"103.0104ms","start":"2025-02-13T19:38:43.682600Z","end":"2025-02-13T19:38:43.785611Z","steps":["trace[1252079459] 'read index received' (duration: 33.638635ms)","trace[1252079459] 'applied index is now lower than readState.Index' (duration: 69.371475ms)"],"step_count":2} Feb 13 19:38:43.786012 etcd-wrapper[1736]: {"level":"warn","ts":"2025-02-13T19:38:43.785670Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"103.061226ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Feb 13 19:38:43.786012 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:43.785692Z","caller":"traceutil/trace.go:171","msg":"trace[559316929] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1186; }","duration":"103.101775ms","start":"2025-02-13T19:38:43.682584Z","end":"2025-02-13T19:38:43.785686Z","steps":["trace[559316929] 'agreement among raft nodes before linearized reading' (duration: 103.053564ms)"],"step_count":1} Feb 13 19:38:43.786012 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:43.785683Z","caller":"traceutil/trace.go:171","msg":"trace[1250486979] transaction","detail":"{read_only:false; response_revision:1186; number_of_response:1; }","duration":"128.709971ms","start":"2025-02-13T19:38:43.656950Z","end":"2025-02-13T19:38:43.785660Z","steps":["trace[1250486979] 'process raft request' (duration: 59.310163ms)","trace[1250486979] 'compare' (duration: 69.296312ms)"],"step_count":2} Feb 13 19:38:51.531434 etcd-wrapper[1736]: {"level":"info","ts":"2025-02-13T19:38:51.531098Z","caller":"traceutil/trace.go:171","msg":"trace[1853757065] transaction","detail":"{read_only:false; response_revision:1215; number_of_response:1; }","duration":"104.894028ms","start":"2025-02-13T19:38:51.426186Z","end":"2025-02-13T19:38:51.531080Z","steps":["trace[1853757065] 'process raft request' (duration: 104.78966ms)"],"step_count":1}