Dec 13 01:33:22.878026 kernel: Linux version 6.6.65-flatcar (build@pony-truck.infra.kinvolk.io) (x86_64-cros-linux-gnu-gcc (Gentoo Hardened 13.3.1_p20240614 p17) 13.3.1 20240614, GNU ld (Gentoo 2.42 p3) 2.42.0) #1 SMP PREEMPT_DYNAMIC Thu Dec 12 23:15:00 -00 2024 Dec 13 01:33:22.878054 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=2fdbba50b59d8c8a9877a81151806ddc16f473fe99b9ba0d8825997d654583ff Dec 13 01:33:22.878068 kernel: BIOS-provided physical RAM map: Dec 13 01:33:22.878077 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable Dec 13 01:33:22.878085 kernel: BIOS-e820: [mem 0x0000000000100000-0x00000000007fffff] usable Dec 13 01:33:22.878093 kernel: BIOS-e820: [mem 0x0000000000800000-0x0000000000807fff] ACPI NVS Dec 13 01:33:22.878102 kernel: BIOS-e820: [mem 0x0000000000808000-0x000000000080afff] usable Dec 13 01:33:22.878111 kernel: BIOS-e820: [mem 0x000000000080b000-0x000000000080bfff] ACPI NVS Dec 13 01:33:22.878119 kernel: BIOS-e820: [mem 0x000000000080c000-0x000000000080ffff] usable Dec 13 01:33:22.878127 kernel: BIOS-e820: [mem 0x0000000000810000-0x00000000008fffff] ACPI NVS Dec 13 01:33:22.878139 kernel: BIOS-e820: [mem 0x0000000000900000-0x000000009c8eefff] usable Dec 13 01:33:22.878147 kernel: BIOS-e820: [mem 0x000000009c8ef000-0x000000009c9eefff] reserved Dec 13 01:33:22.878155 kernel: BIOS-e820: [mem 0x000000009c9ef000-0x000000009caeefff] type 20 Dec 13 01:33:22.878163 kernel: BIOS-e820: [mem 0x000000009caef000-0x000000009cb6efff] reserved Dec 13 01:33:22.878174 kernel: BIOS-e820: [mem 0x000000009cb6f000-0x000000009cb7efff] ACPI data Dec 13 01:33:22.878183 kernel: BIOS-e820: [mem 0x000000009cb7f000-0x000000009cbfefff] ACPI NVS Dec 13 01:33:22.878197 kernel: BIOS-e820: [mem 0x000000009cbff000-0x000000009cf3ffff] usable Dec 13 01:33:22.878207 kernel: BIOS-e820: [mem 0x000000009cf40000-0x000000009cf5ffff] reserved Dec 13 01:33:22.878217 kernel: BIOS-e820: [mem 0x000000009cf60000-0x000000009cffffff] ACPI NVS Dec 13 01:33:22.878226 kernel: BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved Dec 13 01:33:22.878235 kernel: NX (Execute Disable) protection: active Dec 13 01:33:22.878244 kernel: APIC: Static calls initialized Dec 13 01:33:22.878253 kernel: efi: EFI v2.7 by EDK II Dec 13 01:33:22.878271 kernel: efi: SMBIOS=0x9c9ab000 ACPI=0x9cb7e000 ACPI 2.0=0x9cb7e014 MEMATTR=0x9b674118 Dec 13 01:33:22.878280 kernel: SMBIOS 2.8 present. Dec 13 01:33:22.878289 kernel: DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015 Dec 13 01:33:22.878297 kernel: Hypervisor detected: KVM Dec 13 01:33:22.878310 kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00 Dec 13 01:33:22.878318 kernel: kvm-clock: using sched offset of 4032007026 cycles Dec 13 01:33:22.878328 kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns Dec 13 01:33:22.878337 kernel: tsc: Detected 2794.748 MHz processor Dec 13 01:33:22.878347 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Dec 13 01:33:22.878356 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Dec 13 01:33:22.878366 kernel: last_pfn = 0x9cf40 max_arch_pfn = 0x400000000 Dec 13 01:33:22.878375 kernel: MTRR map: 4 entries (2 fixed + 2 variable; max 18), built from 8 variable MTRRs Dec 13 01:33:22.878384 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Dec 13 01:33:22.878396 kernel: Using GB pages for direct mapping Dec 13 01:33:22.878405 kernel: Secure boot disabled Dec 13 01:33:22.878414 kernel: ACPI: Early table checksum verification disabled Dec 13 01:33:22.878424 kernel: ACPI: RSDP 0x000000009CB7E014 000024 (v02 BOCHS ) Dec 13 01:33:22.878438 kernel: ACPI: XSDT 0x000000009CB7D0E8 000054 (v01 BOCHS BXPC 00000001 01000013) Dec 13 01:33:22.878448 kernel: ACPI: FACP 0x000000009CB79000 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878457 kernel: ACPI: DSDT 0x000000009CB7A000 0021A8 (v01 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878470 kernel: ACPI: FACS 0x000000009CBDD000 000040 Dec 13 01:33:22.878480 kernel: ACPI: APIC 0x000000009CB78000 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878490 kernel: ACPI: HPET 0x000000009CB77000 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878499 kernel: ACPI: MCFG 0x000000009CB76000 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878509 kernel: ACPI: WAET 0x000000009CB75000 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) Dec 13 01:33:22.878518 kernel: ACPI: BGRT 0x000000009CB74000 000038 (v01 INTEL EDK2 00000002 01000013) Dec 13 01:33:22.878527 kernel: ACPI: Reserving FACP table memory at [mem 0x9cb79000-0x9cb790f3] Dec 13 01:33:22.878540 kernel: ACPI: Reserving DSDT table memory at [mem 0x9cb7a000-0x9cb7c1a7] Dec 13 01:33:22.878549 kernel: ACPI: Reserving FACS table memory at [mem 0x9cbdd000-0x9cbdd03f] Dec 13 01:33:22.878559 kernel: ACPI: Reserving APIC table memory at [mem 0x9cb78000-0x9cb7808f] Dec 13 01:33:22.878568 kernel: ACPI: Reserving HPET table memory at [mem 0x9cb77000-0x9cb77037] Dec 13 01:33:22.878578 kernel: ACPI: Reserving MCFG table memory at [mem 0x9cb76000-0x9cb7603b] Dec 13 01:33:22.878587 kernel: ACPI: Reserving WAET table memory at [mem 0x9cb75000-0x9cb75027] Dec 13 01:33:22.878597 kernel: ACPI: Reserving BGRT table memory at [mem 0x9cb74000-0x9cb74037] Dec 13 01:33:22.878606 kernel: No NUMA configuration found Dec 13 01:33:22.878616 kernel: Faking a node at [mem 0x0000000000000000-0x000000009cf3ffff] Dec 13 01:33:22.878628 kernel: NODE_DATA(0) allocated [mem 0x9cea6000-0x9ceabfff] Dec 13 01:33:22.878661 kernel: Zone ranges: Dec 13 01:33:22.878672 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Dec 13 01:33:22.878682 kernel: DMA32 [mem 0x0000000001000000-0x000000009cf3ffff] Dec 13 01:33:22.878691 kernel: Normal empty Dec 13 01:33:22.878701 kernel: Movable zone start for each node Dec 13 01:33:22.878710 kernel: Early memory node ranges Dec 13 01:33:22.878720 kernel: node 0: [mem 0x0000000000001000-0x000000000009ffff] Dec 13 01:33:22.878730 kernel: node 0: [mem 0x0000000000100000-0x00000000007fffff] Dec 13 01:33:22.878739 kernel: node 0: [mem 0x0000000000808000-0x000000000080afff] Dec 13 01:33:22.878753 kernel: node 0: [mem 0x000000000080c000-0x000000000080ffff] Dec 13 01:33:22.878762 kernel: node 0: [mem 0x0000000000900000-0x000000009c8eefff] Dec 13 01:33:22.878772 kernel: node 0: [mem 0x000000009cbff000-0x000000009cf3ffff] Dec 13 01:33:22.878781 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000009cf3ffff] Dec 13 01:33:22.878791 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Dec 13 01:33:22.878801 kernel: On node 0, zone DMA: 96 pages in unavailable ranges Dec 13 01:33:22.878810 kernel: On node 0, zone DMA: 8 pages in unavailable ranges Dec 13 01:33:22.878820 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Dec 13 01:33:22.878829 kernel: On node 0, zone DMA: 240 pages in unavailable ranges Dec 13 01:33:22.878842 kernel: On node 0, zone DMA32: 784 pages in unavailable ranges Dec 13 01:33:22.878851 kernel: On node 0, zone DMA32: 12480 pages in unavailable ranges Dec 13 01:33:22.878861 kernel: ACPI: PM-Timer IO Port: 0x608 Dec 13 01:33:22.878870 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Dec 13 01:33:22.878880 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Dec 13 01:33:22.878890 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Dec 13 01:33:22.878900 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Dec 13 01:33:22.878909 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Dec 13 01:33:22.878919 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Dec 13 01:33:22.878931 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Dec 13 01:33:22.878941 kernel: ACPI: Using ACPI (MADT) for SMP configuration information Dec 13 01:33:22.878950 kernel: ACPI: HPET id: 0x8086a201 base: 0xfed00000 Dec 13 01:33:22.878960 kernel: TSC deadline timer available Dec 13 01:33:22.878969 kernel: smpboot: Allowing 4 CPUs, 0 hotplug CPUs Dec 13 01:33:22.878979 kernel: kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() Dec 13 01:33:22.878989 kernel: kvm-guest: KVM setup pv remote TLB flush Dec 13 01:33:22.878998 kernel: kvm-guest: setup PV sched yield Dec 13 01:33:22.879008 kernel: [mem 0xc0000000-0xffffffff] available for PCI devices Dec 13 01:33:22.879017 kernel: Booting paravirtualized kernel on KVM Dec 13 01:33:22.879030 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns Dec 13 01:33:22.879040 kernel: setup_percpu: NR_CPUS:512 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 Dec 13 01:33:22.879049 kernel: percpu: Embedded 58 pages/cpu s197032 r8192 d32344 u524288 Dec 13 01:33:22.879059 kernel: pcpu-alloc: s197032 r8192 d32344 u524288 alloc=1*2097152 Dec 13 01:33:22.879073 kernel: pcpu-alloc: [0] 0 1 2 3 Dec 13 01:33:22.879090 kernel: kvm-guest: PV spinlocks enabled Dec 13 01:33:22.879101 kernel: PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) Dec 13 01:33:22.879112 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=2fdbba50b59d8c8a9877a81151806ddc16f473fe99b9ba0d8825997d654583ff Dec 13 01:33:22.879126 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. Dec 13 01:33:22.879135 kernel: random: crng init done Dec 13 01:33:22.879145 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Dec 13 01:33:22.879154 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Dec 13 01:33:22.879164 kernel: Fallback order for Node 0: 0 Dec 13 01:33:22.879219 kernel: Built 1 zonelists, mobility grouping on. Total pages: 629759 Dec 13 01:33:22.879230 kernel: Policy zone: DMA32 Dec 13 01:33:22.879240 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Dec 13 01:33:22.879250 kernel: Memory: 2395616K/2567000K available (12288K kernel code, 2299K rwdata, 22724K rodata, 42844K init, 2348K bss, 171124K reserved, 0K cma-reserved) Dec 13 01:33:22.879275 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Dec 13 01:33:22.879285 kernel: ftrace: allocating 37902 entries in 149 pages Dec 13 01:33:22.879295 kernel: ftrace: allocated 149 pages with 4 groups Dec 13 01:33:22.879305 kernel: Dynamic Preempt: voluntary Dec 13 01:33:22.879326 kernel: rcu: Preemptible hierarchical RCU implementation. Dec 13 01:33:22.879340 kernel: rcu: RCU event tracing is enabled. Dec 13 01:33:22.879350 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Dec 13 01:33:22.879360 kernel: Trampoline variant of Tasks RCU enabled. Dec 13 01:33:22.879372 kernel: Rude variant of Tasks RCU enabled. Dec 13 01:33:22.879382 kernel: Tracing variant of Tasks RCU enabled. Dec 13 01:33:22.879393 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Dec 13 01:33:22.879403 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Dec 13 01:33:22.879417 kernel: NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16 Dec 13 01:33:22.879427 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Dec 13 01:33:22.879437 kernel: Console: colour dummy device 80x25 Dec 13 01:33:22.879447 kernel: printk: console [ttyS0] enabled Dec 13 01:33:22.879457 kernel: ACPI: Core revision 20230628 Dec 13 01:33:22.879471 kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns Dec 13 01:33:22.879480 kernel: APIC: Switch to symmetric I/O mode setup Dec 13 01:33:22.879490 kernel: x2apic enabled Dec 13 01:33:22.879500 kernel: APIC: Switched APIC routing to: physical x2apic Dec 13 01:33:22.879510 kernel: kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() Dec 13 01:33:22.879520 kernel: kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() Dec 13 01:33:22.879530 kernel: kvm-guest: setup PV IPIs Dec 13 01:33:22.879540 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Dec 13 01:33:22.879550 kernel: tsc: Marking TSC unstable due to TSCs unsynchronized Dec 13 01:33:22.879563 kernel: Calibrating delay loop (skipped) preset value.. 5589.49 BogoMIPS (lpj=2794748) Dec 13 01:33:22.879573 kernel: x86/cpu: User Mode Instruction Prevention (UMIP) activated Dec 13 01:33:22.879583 kernel: Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 Dec 13 01:33:22.879593 kernel: Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 Dec 13 01:33:22.879603 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Dec 13 01:33:22.879613 kernel: Spectre V2 : Mitigation: Retpolines Dec 13 01:33:22.879623 kernel: Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch Dec 13 01:33:22.879633 kernel: Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT Dec 13 01:33:22.879658 kernel: Spectre V2 : Enabling Speculation Barrier for firmware calls Dec 13 01:33:22.879672 kernel: RETBleed: Mitigation: untrained return thunk Dec 13 01:33:22.879683 kernel: Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier Dec 13 01:33:22.879693 kernel: Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl Dec 13 01:33:22.879703 kernel: Speculative Return Stack Overflow: IBPB-extending microcode not applied! Dec 13 01:33:22.879714 kernel: Speculative Return Stack Overflow: WARNING: See https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for mitigation options. Dec 13 01:33:22.879724 kernel: Speculative Return Stack Overflow: Vulnerable: Safe RET, no microcode Dec 13 01:33:22.879734 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Dec 13 01:33:22.879744 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Dec 13 01:33:22.879757 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Dec 13 01:33:22.879767 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Dec 13 01:33:22.879777 kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. Dec 13 01:33:22.879787 kernel: Freeing SMP alternatives memory: 32K Dec 13 01:33:22.879797 kernel: pid_max: default: 32768 minimum: 301 Dec 13 01:33:22.879807 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,integrity Dec 13 01:33:22.879817 kernel: landlock: Up and running. Dec 13 01:33:22.879827 kernel: SELinux: Initializing. Dec 13 01:33:22.879837 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Dec 13 01:33:22.879850 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Dec 13 01:33:22.879860 kernel: smpboot: CPU0: AMD EPYC 7402P 24-Core Processor (family: 0x17, model: 0x31, stepping: 0x0) Dec 13 01:33:22.879871 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Dec 13 01:33:22.879881 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Dec 13 01:33:22.879891 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=4. Dec 13 01:33:22.879901 kernel: Performance Events: Fam17h+ core perfctr, AMD PMU driver. Dec 13 01:33:22.879911 kernel: ... version: 0 Dec 13 01:33:22.879921 kernel: ... bit width: 48 Dec 13 01:33:22.879931 kernel: ... generic registers: 6 Dec 13 01:33:22.879944 kernel: ... value mask: 0000ffffffffffff Dec 13 01:33:22.879954 kernel: ... max period: 00007fffffffffff Dec 13 01:33:22.879964 kernel: ... fixed-purpose events: 0 Dec 13 01:33:22.879974 kernel: ... event mask: 000000000000003f Dec 13 01:33:22.879984 kernel: signal: max sigframe size: 1776 Dec 13 01:33:22.879995 kernel: rcu: Hierarchical SRCU implementation. Dec 13 01:33:22.880006 kernel: rcu: Max phase no-delay instances is 400. Dec 13 01:33:22.880016 kernel: smp: Bringing up secondary CPUs ... Dec 13 01:33:22.880027 kernel: smpboot: x86: Booting SMP configuration: Dec 13 01:33:22.880040 kernel: .... node #0, CPUs: #1 #2 #3 Dec 13 01:33:22.880051 kernel: smp: Brought up 1 node, 4 CPUs Dec 13 01:33:22.880061 kernel: smpboot: Max logical packages: 1 Dec 13 01:33:22.880072 kernel: smpboot: Total of 4 processors activated (22357.98 BogoMIPS) Dec 13 01:33:22.880081 kernel: devtmpfs: initialized Dec 13 01:33:22.880092 kernel: x86/mm: Memory block size: 128MB Dec 13 01:33:22.880102 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00800000-0x00807fff] (32768 bytes) Dec 13 01:33:22.880113 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x0080b000-0x0080bfff] (4096 bytes) Dec 13 01:33:22.880123 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00810000-0x008fffff] (983040 bytes) Dec 13 01:33:22.880137 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cb7f000-0x9cbfefff] (524288 bytes) Dec 13 01:33:22.880147 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cf60000-0x9cffffff] (655360 bytes) Dec 13 01:33:22.880158 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Dec 13 01:33:22.880168 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Dec 13 01:33:22.880179 kernel: pinctrl core: initialized pinctrl subsystem Dec 13 01:33:22.880189 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Dec 13 01:33:22.880200 kernel: audit: initializing netlink subsys (disabled) Dec 13 01:33:22.880210 kernel: audit: type=2000 audit(1734053602.694:1): state=initialized audit_enabled=0 res=1 Dec 13 01:33:22.880248 kernel: thermal_sys: Registered thermal governor 'step_wise' Dec 13 01:33:22.880286 kernel: thermal_sys: Registered thermal governor 'user_space' Dec 13 01:33:22.880296 kernel: cpuidle: using governor menu Dec 13 01:33:22.880306 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Dec 13 01:33:22.880317 kernel: dca service started, version 1.12.1 Dec 13 01:33:22.880327 kernel: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xb0000000-0xbfffffff] (base 0xb0000000) Dec 13 01:33:22.880337 kernel: PCI: MMCONFIG at [mem 0xb0000000-0xbfffffff] reserved as E820 entry Dec 13 01:33:22.880352 kernel: PCI: Using configuration type 1 for base access Dec 13 01:33:22.880363 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Dec 13 01:33:22.880373 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Dec 13 01:33:22.880386 kernel: HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page Dec 13 01:33:22.880397 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Dec 13 01:33:22.880407 kernel: HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page Dec 13 01:33:22.880417 kernel: ACPI: Added _OSI(Module Device) Dec 13 01:33:22.880427 kernel: ACPI: Added _OSI(Processor Device) Dec 13 01:33:22.880437 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) Dec 13 01:33:22.880447 kernel: ACPI: Added _OSI(Processor Aggregator Device) Dec 13 01:33:22.880457 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Dec 13 01:33:22.880467 kernel: ACPI: _OSC evaluation for CPUs failed, trying _PDC Dec 13 01:33:22.880481 kernel: ACPI: Interpreter enabled Dec 13 01:33:22.880490 kernel: ACPI: PM: (supports S0 S3 S5) Dec 13 01:33:22.880500 kernel: ACPI: Using IOAPIC for interrupt routing Dec 13 01:33:22.880510 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Dec 13 01:33:22.880521 kernel: PCI: Using E820 reservations for host bridge windows Dec 13 01:33:22.880531 kernel: ACPI: Enabled 2 GPEs in block 00 to 3F Dec 13 01:33:22.880541 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Dec 13 01:33:22.880783 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Dec 13 01:33:22.880942 kernel: acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR] Dec 13 01:33:22.881088 kernel: acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability] Dec 13 01:33:22.881111 kernel: PCI host bridge to bus 0000:00 Dec 13 01:33:22.881317 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Dec 13 01:33:22.881463 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Dec 13 01:33:22.881608 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Dec 13 01:33:22.881774 kernel: pci_bus 0000:00: root bus resource [mem 0x9d000000-0xafffffff window] Dec 13 01:33:22.881927 kernel: pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] Dec 13 01:33:22.882072 kernel: pci_bus 0000:00: root bus resource [mem 0x800000000-0xfffffffff window] Dec 13 01:33:22.882224 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Dec 13 01:33:22.882417 kernel: pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 Dec 13 01:33:22.882596 kernel: pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 Dec 13 01:33:22.882789 kernel: pci 0000:00:01.0: reg 0x10: [mem 0xc0000000-0xc0ffffff pref] Dec 13 01:33:22.882953 kernel: pci 0000:00:01.0: reg 0x18: [mem 0xc1044000-0xc1044fff] Dec 13 01:33:22.883108 kernel: pci 0000:00:01.0: reg 0x30: [mem 0xffff0000-0xffffffff pref] Dec 13 01:33:22.883272 kernel: pci 0000:00:01.0: BAR 0: assigned to efifb Dec 13 01:33:22.883430 kernel: pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Dec 13 01:33:22.883600 kernel: pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 Dec 13 01:33:22.883787 kernel: pci 0000:00:02.0: reg 0x10: [io 0x6100-0x611f] Dec 13 01:33:22.883964 kernel: pci 0000:00:02.0: reg 0x14: [mem 0xc1043000-0xc1043fff] Dec 13 01:33:22.884115 kernel: pci 0000:00:02.0: reg 0x20: [mem 0x800000000-0x800003fff 64bit pref] Dec 13 01:33:22.884291 kernel: pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 Dec 13 01:33:22.884448 kernel: pci 0000:00:03.0: reg 0x10: [io 0x6000-0x607f] Dec 13 01:33:22.884606 kernel: pci 0000:00:03.0: reg 0x14: [mem 0xc1042000-0xc1042fff] Dec 13 01:33:22.884777 kernel: pci 0000:00:03.0: reg 0x20: [mem 0x800004000-0x800007fff 64bit pref] Dec 13 01:33:22.884944 kernel: pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 Dec 13 01:33:22.885100 kernel: pci 0000:00:04.0: reg 0x10: [io 0x60e0-0x60ff] Dec 13 01:33:22.885274 kernel: pci 0000:00:04.0: reg 0x14: [mem 0xc1041000-0xc1041fff] Dec 13 01:33:22.885431 kernel: pci 0000:00:04.0: reg 0x20: [mem 0x800008000-0x80000bfff 64bit pref] Dec 13 01:33:22.885586 kernel: pci 0000:00:04.0: reg 0x30: [mem 0xfffc0000-0xffffffff pref] Dec 13 01:33:22.885766 kernel: pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 Dec 13 01:33:22.885923 kernel: pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO Dec 13 01:33:22.886090 kernel: pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 Dec 13 01:33:22.886250 kernel: pci 0000:00:1f.2: reg 0x20: [io 0x60c0-0x60df] Dec 13 01:33:22.886423 kernel: pci 0000:00:1f.2: reg 0x24: [mem 0xc1040000-0xc1040fff] Dec 13 01:33:22.886589 kernel: pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 Dec 13 01:33:22.886781 kernel: pci 0000:00:1f.3: reg 0x20: [io 0x6080-0x60bf] Dec 13 01:33:22.886797 kernel: ACPI: PCI: Interrupt link LNKA configured for IRQ 10 Dec 13 01:33:22.886808 kernel: ACPI: PCI: Interrupt link LNKB configured for IRQ 10 Dec 13 01:33:22.886819 kernel: ACPI: PCI: Interrupt link LNKC configured for IRQ 11 Dec 13 01:33:22.886829 kernel: ACPI: PCI: Interrupt link LNKD configured for IRQ 11 Dec 13 01:33:22.886843 kernel: ACPI: PCI: Interrupt link LNKE configured for IRQ 10 Dec 13 01:33:22.886854 kernel: ACPI: PCI: Interrupt link LNKF configured for IRQ 10 Dec 13 01:33:22.886864 kernel: ACPI: PCI: Interrupt link LNKG configured for IRQ 11 Dec 13 01:33:22.886874 kernel: ACPI: PCI: Interrupt link LNKH configured for IRQ 11 Dec 13 01:33:22.886884 kernel: ACPI: PCI: Interrupt link GSIA configured for IRQ 16 Dec 13 01:33:22.886894 kernel: ACPI: PCI: Interrupt link GSIB configured for IRQ 17 Dec 13 01:33:22.886905 kernel: ACPI: PCI: Interrupt link GSIC configured for IRQ 18 Dec 13 01:33:22.886915 kernel: ACPI: PCI: Interrupt link GSID configured for IRQ 19 Dec 13 01:33:22.886925 kernel: ACPI: PCI: Interrupt link GSIE configured for IRQ 20 Dec 13 01:33:22.886939 kernel: ACPI: PCI: Interrupt link GSIF configured for IRQ 21 Dec 13 01:33:22.886949 kernel: ACPI: PCI: Interrupt link GSIG configured for IRQ 22 Dec 13 01:33:22.886959 kernel: ACPI: PCI: Interrupt link GSIH configured for IRQ 23 Dec 13 01:33:22.886969 kernel: iommu: Default domain type: Translated Dec 13 01:33:22.886979 kernel: iommu: DMA domain TLB invalidation policy: lazy mode Dec 13 01:33:22.886989 kernel: efivars: Registered efivars operations Dec 13 01:33:22.886999 kernel: PCI: Using ACPI for IRQ routing Dec 13 01:33:22.887009 kernel: PCI: pci_cache_line_size set to 64 bytes Dec 13 01:33:22.887019 kernel: e820: reserve RAM buffer [mem 0x0080b000-0x008fffff] Dec 13 01:33:22.887032 kernel: e820: reserve RAM buffer [mem 0x00810000-0x008fffff] Dec 13 01:33:22.887042 kernel: e820: reserve RAM buffer [mem 0x9c8ef000-0x9fffffff] Dec 13 01:33:22.887052 kernel: e820: reserve RAM buffer [mem 0x9cf40000-0x9fffffff] Dec 13 01:33:22.887204 kernel: pci 0000:00:01.0: vgaarb: setting as boot VGA device Dec 13 01:33:22.887359 kernel: pci 0000:00:01.0: vgaarb: bridge control possible Dec 13 01:33:22.887507 kernel: pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Dec 13 01:33:22.887521 kernel: vgaarb: loaded Dec 13 01:33:22.887531 kernel: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Dec 13 01:33:22.887541 kernel: hpet0: 3 comparators, 64-bit 100.000000 MHz counter Dec 13 01:33:22.887556 kernel: clocksource: Switched to clocksource kvm-clock Dec 13 01:33:22.887566 kernel: VFS: Disk quotas dquot_6.6.0 Dec 13 01:33:22.887576 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Dec 13 01:33:22.887586 kernel: pnp: PnP ACPI init Dec 13 01:33:22.887800 kernel: system 00:05: [mem 0xb0000000-0xbfffffff window] has been reserved Dec 13 01:33:22.887813 kernel: pnp: PnP ACPI: found 6 devices Dec 13 01:33:22.887821 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Dec 13 01:33:22.887828 kernel: NET: Registered PF_INET protocol family Dec 13 01:33:22.887839 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Dec 13 01:33:22.887847 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Dec 13 01:33:22.887855 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Dec 13 01:33:22.887862 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Dec 13 01:33:22.887869 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Dec 13 01:33:22.887876 kernel: TCP: Hash tables configured (established 32768 bind 32768) Dec 13 01:33:22.887884 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Dec 13 01:33:22.887891 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Dec 13 01:33:22.887899 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Dec 13 01:33:22.887908 kernel: NET: Registered PF_XDP protocol family Dec 13 01:33:22.888027 kernel: pci 0000:00:04.0: can't claim BAR 6 [mem 0xfffc0000-0xffffffff pref]: no compatible bridge window Dec 13 01:33:22.888143 kernel: pci 0000:00:04.0: BAR 6: assigned [mem 0x9d000000-0x9d03ffff pref] Dec 13 01:33:22.888256 kernel: pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] Dec 13 01:33:22.888375 kernel: pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] Dec 13 01:33:22.888481 kernel: pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] Dec 13 01:33:22.888588 kernel: pci_bus 0000:00: resource 7 [mem 0x9d000000-0xafffffff window] Dec 13 01:33:22.888719 kernel: pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window] Dec 13 01:33:22.888833 kernel: pci_bus 0000:00: resource 9 [mem 0x800000000-0xfffffffff window] Dec 13 01:33:22.888843 kernel: PCI: CLS 0 bytes, default 64 Dec 13 01:33:22.888850 kernel: Initialise system trusted keyrings Dec 13 01:33:22.888857 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Dec 13 01:33:22.888865 kernel: Key type asymmetric registered Dec 13 01:33:22.888872 kernel: Asymmetric key parser 'x509' registered Dec 13 01:33:22.888879 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251) Dec 13 01:33:22.888886 kernel: io scheduler mq-deadline registered Dec 13 01:33:22.888893 kernel: io scheduler kyber registered Dec 13 01:33:22.888903 kernel: io scheduler bfq registered Dec 13 01:33:22.888911 kernel: ioatdma: Intel(R) QuickData Technology Driver 5.00 Dec 13 01:33:22.888918 kernel: ACPI: \_SB_.GSIG: Enabled at IRQ 22 Dec 13 01:33:22.888926 kernel: ACPI: \_SB_.GSIH: Enabled at IRQ 23 Dec 13 01:33:22.888933 kernel: ACPI: \_SB_.GSIE: Enabled at IRQ 20 Dec 13 01:33:22.888940 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Dec 13 01:33:22.888947 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Dec 13 01:33:22.888954 kernel: i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Dec 13 01:33:22.888962 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Dec 13 01:33:22.888971 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Dec 13 01:33:22.889115 kernel: rtc_cmos 00:04: RTC can wake from S4 Dec 13 01:33:22.889130 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 Dec 13 01:33:22.889280 kernel: rtc_cmos 00:04: registered as rtc0 Dec 13 01:33:22.889426 kernel: rtc_cmos 00:04: setting system clock to 2024-12-13T01:33:22 UTC (1734053602) Dec 13 01:33:22.889571 kernel: rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram, hpet irqs Dec 13 01:33:22.889585 kernel: amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled Dec 13 01:33:22.889600 kernel: efifb: probing for efifb Dec 13 01:33:22.889611 kernel: efifb: framebuffer at 0xc0000000, using 1408k, total 1408k Dec 13 01:33:22.889621 kernel: efifb: mode is 800x600x24, linelength=2400, pages=1 Dec 13 01:33:22.889631 kernel: efifb: scrolling: redraw Dec 13 01:33:22.889671 kernel: efifb: Truecolor: size=0:8:8:8, shift=0:16:8:0 Dec 13 01:33:22.889682 kernel: Console: switching to colour frame buffer device 100x37 Dec 13 01:33:22.889715 kernel: fb0: EFI VGA frame buffer device Dec 13 01:33:22.889729 kernel: pstore: Using crash dump compression: deflate Dec 13 01:33:22.889739 kernel: pstore: Registered efi_pstore as persistent store backend Dec 13 01:33:22.889753 kernel: NET: Registered PF_INET6 protocol family Dec 13 01:33:22.889763 kernel: Segment Routing with IPv6 Dec 13 01:33:22.889774 kernel: In-situ OAM (IOAM) with IPv6 Dec 13 01:33:22.889784 kernel: NET: Registered PF_PACKET protocol family Dec 13 01:33:22.889795 kernel: Key type dns_resolver registered Dec 13 01:33:22.889805 kernel: IPI shorthand broadcast: enabled Dec 13 01:33:22.889816 kernel: sched_clock: Marking stable (545002168, 113813473)->(707732641, -48917000) Dec 13 01:33:22.889827 kernel: registered taskstats version 1 Dec 13 01:33:22.889837 kernel: Loading compiled-in X.509 certificates Dec 13 01:33:22.889848 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.6.65-flatcar: c82d546f528d79a5758dcebbc47fb6daf92836a0' Dec 13 01:33:22.889861 kernel: Key type .fscrypt registered Dec 13 01:33:22.889871 kernel: Key type fscrypt-provisioning registered Dec 13 01:33:22.889882 kernel: ima: No TPM chip found, activating TPM-bypass! Dec 13 01:33:22.889893 kernel: ima: Allocated hash algorithm: sha1 Dec 13 01:33:22.889903 kernel: ima: No architecture policies found Dec 13 01:33:22.889914 kernel: clk: Disabling unused clocks Dec 13 01:33:22.889924 kernel: Freeing unused kernel image (initmem) memory: 42844K Dec 13 01:33:22.889935 kernel: Write protecting the kernel read-only data: 36864k Dec 13 01:33:22.889949 kernel: Freeing unused kernel image (rodata/data gap) memory: 1852K Dec 13 01:33:22.889959 kernel: Run /init as init process Dec 13 01:33:22.889970 kernel: with arguments: Dec 13 01:33:22.889980 kernel: /init Dec 13 01:33:22.889990 kernel: with environment: Dec 13 01:33:22.890001 kernel: HOME=/ Dec 13 01:33:22.890011 kernel: TERM=linux Dec 13 01:33:22.890022 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a Dec 13 01:33:22.890035 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) Dec 13 01:33:22.890051 systemd[1]: Detected virtualization kvm. Dec 13 01:33:22.890063 systemd[1]: Detected architecture x86-64. Dec 13 01:33:22.890074 systemd[1]: Running in initrd. Dec 13 01:33:22.890088 systemd[1]: No hostname configured, using default hostname. Dec 13 01:33:22.890104 systemd[1]: Hostname set to . Dec 13 01:33:22.890116 systemd[1]: Initializing machine ID from VM UUID. Dec 13 01:33:22.890128 systemd[1]: Queued start job for default target initrd.target. Dec 13 01:33:22.890139 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Dec 13 01:33:22.890151 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Dec 13 01:33:22.890163 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Dec 13 01:33:22.890175 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Dec 13 01:33:22.890186 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Dec 13 01:33:22.890202 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Dec 13 01:33:22.890216 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... Dec 13 01:33:22.890227 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... Dec 13 01:33:22.890239 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Dec 13 01:33:22.890250 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Dec 13 01:33:22.890270 systemd[1]: Reached target paths.target - Path Units. Dec 13 01:33:22.890282 systemd[1]: Reached target slices.target - Slice Units. Dec 13 01:33:22.890297 systemd[1]: Reached target swap.target - Swaps. Dec 13 01:33:22.890308 systemd[1]: Reached target timers.target - Timer Units. Dec 13 01:33:22.890319 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Dec 13 01:33:22.890331 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Dec 13 01:33:22.890342 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Dec 13 01:33:22.890354 systemd[1]: Listening on systemd-journald.socket - Journal Socket. Dec 13 01:33:22.890365 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Dec 13 01:33:22.890377 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Dec 13 01:33:22.890391 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Dec 13 01:33:22.890403 systemd[1]: Reached target sockets.target - Socket Units. Dec 13 01:33:22.890414 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Dec 13 01:33:22.890426 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Dec 13 01:33:22.890437 systemd[1]: Finished network-cleanup.service - Network Cleanup. Dec 13 01:33:22.890448 systemd[1]: Starting systemd-fsck-usr.service... Dec 13 01:33:22.890459 systemd[1]: Starting systemd-journald.service - Journal Service... Dec 13 01:33:22.890471 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Dec 13 01:33:22.890482 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:22.890497 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Dec 13 01:33:22.890508 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Dec 13 01:33:22.890519 systemd[1]: Finished systemd-fsck-usr.service. Dec 13 01:33:22.890532 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Dec 13 01:33:22.890565 systemd-journald[193]: Collecting audit messages is disabled. Dec 13 01:33:22.890596 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:22.890608 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Dec 13 01:33:22.890620 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Dec 13 01:33:22.890634 systemd-journald[193]: Journal started Dec 13 01:33:22.890690 systemd-journald[193]: Runtime Journal (/run/log/journal/2d8f473ab1b44d0ca8f8198c9f67f72f) is 6.0M, max 48.3M, 42.2M free. Dec 13 01:33:22.890734 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Dec 13 01:33:22.879114 systemd-modules-load[194]: Inserted module 'overlay' Dec 13 01:33:22.898931 systemd[1]: Started systemd-journald.service - Journal Service. Dec 13 01:33:22.898796 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Dec 13 01:33:22.911493 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Dec 13 01:33:22.911901 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Dec 13 01:33:22.915202 kernel: Bridge firewalling registered Dec 13 01:33:22.915196 systemd-modules-load[194]: Inserted module 'br_netfilter' Dec 13 01:33:22.916452 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Dec 13 01:33:22.918718 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Dec 13 01:33:22.921322 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Dec 13 01:33:22.935811 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Dec 13 01:33:22.938554 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Dec 13 01:33:22.945713 dracut-cmdline[224]: dracut-dracut-053 Dec 13 01:33:22.948287 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=2fdbba50b59d8c8a9877a81151806ddc16f473fe99b9ba0d8825997d654583ff Dec 13 01:33:22.956152 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Dec 13 01:33:22.957990 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Dec 13 01:33:22.991790 systemd-resolved[250]: Positive Trust Anchors: Dec 13 01:33:22.991802 systemd-resolved[250]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Dec 13 01:33:22.991832 systemd-resolved[250]: 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 Dec 13 01:33:22.994203 systemd-resolved[250]: Defaulting to hostname 'linux'. Dec 13 01:33:22.995320 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Dec 13 01:33:23.002747 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Dec 13 01:33:23.026663 kernel: SCSI subsystem initialized Dec 13 01:33:23.035659 kernel: Loading iSCSI transport class v2.0-870. Dec 13 01:33:23.046665 kernel: iscsi: registered transport (tcp) Dec 13 01:33:23.066658 kernel: iscsi: registered transport (qla4xxx) Dec 13 01:33:23.066674 kernel: QLogic iSCSI HBA Driver Dec 13 01:33:23.107731 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Dec 13 01:33:23.113781 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Dec 13 01:33:23.137725 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Dec 13 01:33:23.137765 kernel: device-mapper: uevent: version 1.0.3 Dec 13 01:33:23.138767 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com Dec 13 01:33:23.177666 kernel: raid6: avx2x4 gen() 30518 MB/s Dec 13 01:33:23.194658 kernel: raid6: avx2x2 gen() 31157 MB/s Dec 13 01:33:23.211747 kernel: raid6: avx2x1 gen() 25981 MB/s Dec 13 01:33:23.211768 kernel: raid6: using algorithm avx2x2 gen() 31157 MB/s Dec 13 01:33:23.229750 kernel: raid6: .... xor() 19834 MB/s, rmw enabled Dec 13 01:33:23.229770 kernel: raid6: using avx2x2 recovery algorithm Dec 13 01:33:23.249659 kernel: xor: automatically using best checksumming function avx Dec 13 01:33:23.400675 kernel: Btrfs loaded, zoned=no, fsverity=no Dec 13 01:33:23.412328 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Dec 13 01:33:23.420801 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Dec 13 01:33:23.433823 systemd-udevd[413]: Using default interface naming scheme 'v255'. Dec 13 01:33:23.438303 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Dec 13 01:33:23.449770 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Dec 13 01:33:23.461380 dracut-pre-trigger[420]: rd.md=0: removing MD RAID activation Dec 13 01:33:23.488892 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Dec 13 01:33:23.504789 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Dec 13 01:33:23.566592 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Dec 13 01:33:23.580819 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Dec 13 01:33:23.593688 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Dec 13 01:33:23.594996 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Dec 13 01:33:23.604946 kernel: virtio_blk virtio1: 4/0/0 default/read/poll queues Dec 13 01:33:23.615093 kernel: virtio_blk virtio1: [vda] 9289728 512-byte logical blocks (4.76 GB/4.43 GiB) Dec 13 01:33:23.615292 kernel: cryptd: max_cpu_qlen set to 1000 Dec 13 01:33:23.615309 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Dec 13 01:33:23.597018 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Dec 13 01:33:23.598214 systemd[1]: Reached target remote-fs.target - Remote File Systems. Dec 13 01:33:23.611850 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Dec 13 01:33:23.630446 kernel: AVX2 version of gcm_enc/dec engaged. Dec 13 01:33:23.630500 kernel: AES CTR mode by8 optimization enabled Dec 13 01:33:23.629825 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Dec 13 01:33:23.629971 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Dec 13 01:33:23.636200 systemd[1]: Stopping dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Dec 13 01:33:23.641497 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Dec 13 01:33:23.642391 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:23.645378 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:23.655654 kernel: BTRFS: device label OEM devid 1 transid 12 /dev/vda6 scanned by (udev-worker) (461) Dec 13 01:33:23.655688 kernel: libata version 3.00 loaded. Dec 13 01:33:23.656154 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:23.657233 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Dec 13 01:33:23.669682 kernel: BTRFS: device fsid c3b72f8a-27ca-4d37-9d0e-1ec3c4bdc3be devid 1 transid 41 /dev/vda3 scanned by (udev-worker) (459) Dec 13 01:33:23.675611 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:23.679703 kernel: ahci 0000:00:1f.2: version 3.0 Dec 13 01:33:23.691509 kernel: ACPI: \_SB_.GSIA: Enabled at IRQ 16 Dec 13 01:33:23.691528 kernel: ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode Dec 13 01:33:23.691730 kernel: ahci 0000:00:1f.2: flags: 64bit ncq only Dec 13 01:33:23.691911 kernel: scsi host0: ahci Dec 13 01:33:23.692102 kernel: scsi host1: ahci Dec 13 01:33:23.692301 kernel: scsi host2: ahci Dec 13 01:33:23.692506 kernel: scsi host3: ahci Dec 13 01:33:23.692708 kernel: scsi host4: ahci Dec 13 01:33:23.692888 kernel: scsi host5: ahci Dec 13 01:33:23.693068 kernel: ata1: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040100 irq 34 Dec 13 01:33:23.693084 kernel: ata2: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040180 irq 34 Dec 13 01:33:23.693102 kernel: ata3: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040200 irq 34 Dec 13 01:33:23.693116 kernel: ata4: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040280 irq 34 Dec 13 01:33:23.693129 kernel: ata5: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040300 irq 34 Dec 13 01:33:23.693143 kernel: ata6: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040380 irq 34 Dec 13 01:33:23.683389 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Dec 13 01:33:23.691951 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Dec 13 01:33:23.706374 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Dec 13 01:33:23.711719 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132. Dec 13 01:33:23.712984 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Dec 13 01:33:23.728779 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Dec 13 01:33:23.729935 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Dec 13 01:33:23.729996 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:23.732292 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:23.734196 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:23.740097 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Dec 13 01:33:23.745667 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Dec 13 01:33:23.752090 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:23.764818 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Dec 13 01:33:23.791465 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Dec 13 01:33:24.000914 kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Dec 13 01:33:24.000973 kernel: ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 Dec 13 01:33:24.000988 kernel: ata3.00: applying bridge limits Dec 13 01:33:24.001002 kernel: ata6: SATA link down (SStatus 0 SControl 300) Dec 13 01:33:24.001015 kernel: ata2: SATA link down (SStatus 0 SControl 300) Dec 13 01:33:24.002657 kernel: ata5: SATA link down (SStatus 0 SControl 300) Dec 13 01:33:24.002680 kernel: ata4: SATA link down (SStatus 0 SControl 300) Dec 13 01:33:24.003669 kernel: ata1: SATA link down (SStatus 0 SControl 300) Dec 13 01:33:24.004665 kernel: ata3.00: configured for UDMA/100 Dec 13 01:33:24.004689 kernel: scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 Dec 13 01:33:24.054161 kernel: sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Dec 13 01:33:24.066149 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Dec 13 01:33:24.066382 kernel: sr 2:0:0:0: Attached scsi CD-ROM sr0 Dec 13 01:33:24.750272 disk-uuid[557]: The operation has completed successfully. Dec 13 01:33:24.752291 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Dec 13 01:33:24.780590 systemd[1]: disk-uuid.service: Deactivated successfully. Dec 13 01:33:24.780773 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Dec 13 01:33:24.808851 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... Dec 13 01:33:24.814725 sh[596]: Success Dec 13 01:33:24.827726 kernel: device-mapper: verity: sha256 using implementation "sha256-ni" Dec 13 01:33:24.858503 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. Dec 13 01:33:24.871927 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... Dec 13 01:33:24.874142 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. Dec 13 01:33:24.885709 kernel: BTRFS info (device dm-0): first mount of filesystem c3b72f8a-27ca-4d37-9d0e-1ec3c4bdc3be Dec 13 01:33:24.885739 kernel: BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm Dec 13 01:33:24.885750 kernel: BTRFS warning (device dm-0): 'nologreplay' is deprecated, use 'rescue=nologreplay' instead Dec 13 01:33:24.888078 kernel: BTRFS info (device dm-0): disabling log replay at mount time Dec 13 01:33:24.888094 kernel: BTRFS info (device dm-0): using free space tree Dec 13 01:33:24.891481 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. Dec 13 01:33:24.892540 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Dec 13 01:33:24.901765 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Dec 13 01:33:24.903481 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Dec 13 01:33:24.912130 kernel: BTRFS info (device vda6): first mount of filesystem db063747-cac8-4176-8963-c216c1b11dcb Dec 13 01:33:24.912163 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Dec 13 01:33:24.912174 kernel: BTRFS info (device vda6): using free space tree Dec 13 01:33:24.915677 kernel: BTRFS info (device vda6): auto enabling async discard Dec 13 01:33:24.924043 systemd[1]: mnt-oem.mount: Deactivated successfully. Dec 13 01:33:24.926660 kernel: BTRFS info (device vda6): last unmount of filesystem db063747-cac8-4176-8963-c216c1b11dcb Dec 13 01:33:24.935406 systemd[1]: Finished ignition-setup.service - Ignition (setup). Dec 13 01:33:24.938819 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Dec 13 01:33:24.995451 ignition[694]: Ignition 2.19.0 Dec 13 01:33:24.995461 ignition[694]: Stage: fetch-offline Dec 13 01:33:24.995500 ignition[694]: no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:24.995510 ignition[694]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:24.995600 ignition[694]: parsed url from cmdline: "" Dec 13 01:33:24.995604 ignition[694]: no config URL provided Dec 13 01:33:24.995609 ignition[694]: reading system config file "/usr/lib/ignition/user.ign" Dec 13 01:33:24.995618 ignition[694]: no config at "/usr/lib/ignition/user.ign" Dec 13 01:33:24.995665 ignition[694]: op(1): [started] loading QEMU firmware config module Dec 13 01:33:24.995670 ignition[694]: op(1): executing: "modprobe" "qemu_fw_cfg" Dec 13 01:33:25.002543 ignition[694]: op(1): [finished] loading QEMU firmware config module Dec 13 01:33:25.004514 ignition[694]: parsing config with SHA512: 3f3ecb8df2c4f1ad9591fb37e62c1563c60066dc18765f205f1af8514b2321c11ffba553e6784b4fce026c3342a6892cef161dd12b1057d94d75f0ed361c5023 Dec 13 01:33:25.010504 unknown[694]: fetched base config from "system" Dec 13 01:33:25.010517 unknown[694]: fetched user config from "qemu" Dec 13 01:33:25.010695 ignition[694]: fetch-offline: fetch-offline passed Dec 13 01:33:25.010771 ignition[694]: Ignition finished successfully Dec 13 01:33:25.012932 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Dec 13 01:33:25.015338 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Dec 13 01:33:25.029779 systemd[1]: Starting systemd-networkd.service - Network Configuration... Dec 13 01:33:25.050797 systemd-networkd[786]: lo: Link UP Dec 13 01:33:25.050805 systemd-networkd[786]: lo: Gained carrier Dec 13 01:33:25.052327 systemd-networkd[786]: Enumeration completed Dec 13 01:33:25.052421 systemd[1]: Started systemd-networkd.service - Network Configuration. Dec 13 01:33:25.052770 systemd-networkd[786]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Dec 13 01:33:25.052774 systemd-networkd[786]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Dec 13 01:33:25.054518 systemd-networkd[786]: eth0: Link UP Dec 13 01:33:25.054523 systemd-networkd[786]: eth0: Gained carrier Dec 13 01:33:25.054530 systemd-networkd[786]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Dec 13 01:33:25.054741 systemd[1]: Reached target network.target - Network. Dec 13 01:33:25.056562 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Dec 13 01:33:25.064767 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Dec 13 01:33:25.076687 systemd-networkd[786]: eth0: DHCPv4 address 10.0.0.95/16, gateway 10.0.0.1 acquired from 10.0.0.1 Dec 13 01:33:25.076792 ignition[788]: Ignition 2.19.0 Dec 13 01:33:25.076799 ignition[788]: Stage: kargs Dec 13 01:33:25.076963 ignition[788]: no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:25.076974 ignition[788]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:25.081044 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Dec 13 01:33:25.077504 ignition[788]: kargs: kargs passed Dec 13 01:33:25.077547 ignition[788]: Ignition finished successfully Dec 13 01:33:25.090764 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Dec 13 01:33:25.105810 ignition[797]: Ignition 2.19.0 Dec 13 01:33:25.105820 ignition[797]: Stage: disks Dec 13 01:33:25.105989 ignition[797]: no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:25.106001 ignition[797]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:25.108720 systemd[1]: Finished ignition-disks.service - Ignition (disks). Dec 13 01:33:25.106565 ignition[797]: disks: disks passed Dec 13 01:33:25.110417 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Dec 13 01:33:25.106610 ignition[797]: Ignition finished successfully Dec 13 01:33:25.112333 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Dec 13 01:33:25.112891 systemd[1]: Reached target local-fs.target - Local File Systems. Dec 13 01:33:25.113219 systemd[1]: Reached target sysinit.target - System Initialization. Dec 13 01:33:25.113543 systemd[1]: Reached target basic.target - Basic System. Dec 13 01:33:25.123760 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Dec 13 01:33:25.136624 systemd-fsck[807]: ROOT: clean, 14/553520 files, 52654/553472 blocks Dec 13 01:33:25.142497 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Dec 13 01:33:25.155705 systemd[1]: Mounting sysroot.mount - /sysroot... Dec 13 01:33:25.243654 kernel: EXT4-fs (vda9): mounted filesystem 390119fa-ab9c-4f50-b046-3b5c76c46193 r/w with ordered data mode. Quota mode: none. Dec 13 01:33:25.243795 systemd[1]: Mounted sysroot.mount - /sysroot. Dec 13 01:33:25.244896 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Dec 13 01:33:25.259716 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Dec 13 01:33:25.261252 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Dec 13 01:33:25.262910 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Dec 13 01:33:25.262945 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Dec 13 01:33:25.262966 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Dec 13 01:33:25.270506 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Dec 13 01:33:25.272546 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Dec 13 01:33:25.304663 kernel: BTRFS: device label OEM devid 1 transid 13 /dev/vda6 scanned by mount (815) Dec 13 01:33:25.307064 kernel: BTRFS info (device vda6): first mount of filesystem db063747-cac8-4176-8963-c216c1b11dcb Dec 13 01:33:25.307125 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Dec 13 01:33:25.307148 kernel: BTRFS info (device vda6): using free space tree Dec 13 01:33:25.310659 kernel: BTRFS info (device vda6): auto enabling async discard Dec 13 01:33:25.312246 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Dec 13 01:33:25.320157 initrd-setup-root[840]: cut: /sysroot/etc/passwd: No such file or directory Dec 13 01:33:25.325258 initrd-setup-root[847]: cut: /sysroot/etc/group: No such file or directory Dec 13 01:33:25.329109 initrd-setup-root[854]: cut: /sysroot/etc/shadow: No such file or directory Dec 13 01:33:25.333790 initrd-setup-root[861]: cut: /sysroot/etc/gshadow: No such file or directory Dec 13 01:33:25.416435 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Dec 13 01:33:25.428710 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Dec 13 01:33:25.431192 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Dec 13 01:33:25.437666 kernel: BTRFS info (device vda6): last unmount of filesystem db063747-cac8-4176-8963-c216c1b11dcb Dec 13 01:33:25.456806 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Dec 13 01:33:25.461793 ignition[929]: INFO : Ignition 2.19.0 Dec 13 01:33:25.461793 ignition[929]: INFO : Stage: mount Dec 13 01:33:25.463478 ignition[929]: INFO : no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:25.463478 ignition[929]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:25.463478 ignition[929]: INFO : mount: mount passed Dec 13 01:33:25.463478 ignition[929]: INFO : Ignition finished successfully Dec 13 01:33:25.464838 systemd[1]: Finished ignition-mount.service - Ignition (mount). Dec 13 01:33:25.472804 systemd[1]: Starting ignition-files.service - Ignition (files)... Dec 13 01:33:25.885087 systemd[1]: sysroot-oem.mount: Deactivated successfully. Dec 13 01:33:25.896909 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Dec 13 01:33:25.904299 kernel: BTRFS: device label OEM devid 1 transid 14 /dev/vda6 scanned by mount (943) Dec 13 01:33:25.904330 kernel: BTRFS info (device vda6): first mount of filesystem db063747-cac8-4176-8963-c216c1b11dcb Dec 13 01:33:25.904345 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Dec 13 01:33:25.905864 kernel: BTRFS info (device vda6): using free space tree Dec 13 01:33:25.908666 kernel: BTRFS info (device vda6): auto enabling async discard Dec 13 01:33:25.909703 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Dec 13 01:33:25.940425 ignition[960]: INFO : Ignition 2.19.0 Dec 13 01:33:25.940425 ignition[960]: INFO : Stage: files Dec 13 01:33:25.942582 ignition[960]: INFO : no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:25.942582 ignition[960]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:25.942582 ignition[960]: DEBUG : files: compiled without relabeling support, skipping Dec 13 01:33:25.942582 ignition[960]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Dec 13 01:33:25.942582 ignition[960]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Dec 13 01:33:25.949954 ignition[960]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Dec 13 01:33:25.949954 ignition[960]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Dec 13 01:33:25.949954 ignition[960]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Dec 13 01:33:25.949954 ignition[960]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/etc/flatcar/update.conf" Dec 13 01:33:25.949954 ignition[960]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/etc/flatcar/update.conf" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(4): [started] processing unit "etcd-member.service" Dec 13 01:33:25.949954 ignition[960]: 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" Dec 13 01:33:25.949954 ignition[960]: 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" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(4): [finished] processing unit "etcd-member.service" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(6): [started] processing unit "coreos-metadata.service" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(6): op(7): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(6): op(7): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(6): [finished] processing unit "coreos-metadata.service" Dec 13 01:33:25.949954 ignition[960]: INFO : files: op(8): [started] setting preset to disabled for "coreos-metadata.service" Dec 13 01:33:25.944892 unknown[960]: wrote ssh authorized keys file for user: core Dec 13 01:33:25.979837 ignition[960]: INFO : files: op(8): op(9): [started] removing enablement symlink(s) for "coreos-metadata.service" Dec 13 01:33:25.984691 ignition[960]: INFO : files: op(8): op(9): [finished] removing enablement symlink(s) for "coreos-metadata.service" Dec 13 01:33:25.986244 ignition[960]: INFO : files: op(8): [finished] setting preset to disabled for "coreos-metadata.service" Dec 13 01:33:25.986244 ignition[960]: INFO : files: op(a): [started] setting preset to enabled for "etcd-member.service" Dec 13 01:33:25.986244 ignition[960]: INFO : files: op(a): [finished] setting preset to enabled for "etcd-member.service" Dec 13 01:33:25.986244 ignition[960]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Dec 13 01:33:25.986244 ignition[960]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Dec 13 01:33:25.986244 ignition[960]: INFO : files: files passed Dec 13 01:33:25.986244 ignition[960]: INFO : Ignition finished successfully Dec 13 01:33:25.987447 systemd[1]: Finished ignition-files.service - Ignition (files). Dec 13 01:33:25.998792 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Dec 13 01:33:26.000498 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Dec 13 01:33:26.003950 systemd[1]: ignition-quench.service: Deactivated successfully. Dec 13 01:33:26.004090 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Dec 13 01:33:26.010359 initrd-setup-root-after-ignition[989]: grep: /sysroot/oem/oem-release: No such file or directory Dec 13 01:33:26.013475 initrd-setup-root-after-ignition[991]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Dec 13 01:33:26.013475 initrd-setup-root-after-ignition[991]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Dec 13 01:33:26.016955 initrd-setup-root-after-ignition[995]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Dec 13 01:33:26.020123 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Dec 13 01:33:26.022887 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Dec 13 01:33:26.030774 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Dec 13 01:33:26.054513 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Dec 13 01:33:26.055630 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Dec 13 01:33:26.058405 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Dec 13 01:33:26.060551 systemd[1]: Reached target initrd.target - Initrd Default Target. Dec 13 01:33:26.062745 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Dec 13 01:33:26.064965 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Dec 13 01:33:26.083726 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Dec 13 01:33:26.093846 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Dec 13 01:33:26.102806 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Dec 13 01:33:26.104181 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Dec 13 01:33:26.106575 systemd[1]: Stopped target timers.target - Timer Units. Dec 13 01:33:26.108696 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Dec 13 01:33:26.108811 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Dec 13 01:33:26.110953 systemd[1]: Stopped target initrd.target - Initrd Default Target. Dec 13 01:33:26.112725 systemd[1]: Stopped target basic.target - Basic System. Dec 13 01:33:26.114911 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Dec 13 01:33:26.117116 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Dec 13 01:33:26.119340 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Dec 13 01:33:26.121474 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Dec 13 01:33:26.123681 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Dec 13 01:33:26.126061 systemd[1]: Stopped target sysinit.target - System Initialization. Dec 13 01:33:26.128075 systemd[1]: Stopped target local-fs.target - Local File Systems. Dec 13 01:33:26.130279 systemd[1]: Stopped target swap.target - Swaps. Dec 13 01:33:26.131983 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Dec 13 01:33:26.132124 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Dec 13 01:33:26.134339 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Dec 13 01:33:26.135926 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Dec 13 01:33:26.138217 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Dec 13 01:33:26.138342 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Dec 13 01:33:26.140480 systemd[1]: dracut-initqueue.service: Deactivated successfully. Dec 13 01:33:26.140585 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Dec 13 01:33:26.142783 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Dec 13 01:33:26.142892 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Dec 13 01:33:26.144862 systemd[1]: Stopped target paths.target - Path Units. Dec 13 01:33:26.146554 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Dec 13 01:33:26.150695 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Dec 13 01:33:26.152082 systemd[1]: Stopped target slices.target - Slice Units. Dec 13 01:33:26.154042 systemd[1]: Stopped target sockets.target - Socket Units. Dec 13 01:33:26.155772 systemd[1]: iscsid.socket: Deactivated successfully. Dec 13 01:33:26.155862 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Dec 13 01:33:26.157746 systemd[1]: iscsiuio.socket: Deactivated successfully. Dec 13 01:33:26.157833 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Dec 13 01:33:26.160157 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Dec 13 01:33:26.160273 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Dec 13 01:33:26.162205 systemd[1]: ignition-files.service: Deactivated successfully. Dec 13 01:33:26.162308 systemd[1]: Stopped ignition-files.service - Ignition (files). Dec 13 01:33:26.179786 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Dec 13 01:33:26.181351 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Dec 13 01:33:26.182479 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Dec 13 01:33:26.182593 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Dec 13 01:33:26.184602 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Dec 13 01:33:26.184720 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Dec 13 01:33:26.189475 systemd[1]: initrd-cleanup.service: Deactivated successfully. Dec 13 01:33:26.189587 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Dec 13 01:33:26.193470 ignition[1015]: INFO : Ignition 2.19.0 Dec 13 01:33:26.193470 ignition[1015]: INFO : Stage: umount Dec 13 01:33:26.193470 ignition[1015]: INFO : no configs at "/usr/lib/ignition/base.d" Dec 13 01:33:26.193470 ignition[1015]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Dec 13 01:33:26.198506 ignition[1015]: INFO : umount: umount passed Dec 13 01:33:26.198506 ignition[1015]: INFO : Ignition finished successfully Dec 13 01:33:26.196225 systemd[1]: ignition-mount.service: Deactivated successfully. Dec 13 01:33:26.196352 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Dec 13 01:33:26.198675 systemd[1]: Stopped target network.target - Network. Dec 13 01:33:26.200372 systemd[1]: ignition-disks.service: Deactivated successfully. Dec 13 01:33:26.200425 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Dec 13 01:33:26.202380 systemd[1]: ignition-kargs.service: Deactivated successfully. Dec 13 01:33:26.202428 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Dec 13 01:33:26.204543 systemd[1]: ignition-setup.service: Deactivated successfully. Dec 13 01:33:26.204590 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Dec 13 01:33:26.206702 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Dec 13 01:33:26.206752 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Dec 13 01:33:26.209026 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Dec 13 01:33:26.211188 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Dec 13 01:33:26.214111 systemd[1]: sysroot-boot.mount: Deactivated successfully. Dec 13 01:33:26.214675 systemd-networkd[786]: eth0: DHCPv6 lease lost Dec 13 01:33:26.214724 systemd[1]: sysroot-boot.service: Deactivated successfully. Dec 13 01:33:26.214831 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Dec 13 01:33:26.216997 systemd[1]: systemd-networkd.service: Deactivated successfully. Dec 13 01:33:26.217126 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Dec 13 01:33:26.219713 systemd[1]: systemd-networkd.socket: Deactivated successfully. Dec 13 01:33:26.219770 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Dec 13 01:33:26.221251 systemd[1]: initrd-setup-root.service: Deactivated successfully. Dec 13 01:33:26.221302 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Dec 13 01:33:26.232720 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Dec 13 01:33:26.234299 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Dec 13 01:33:26.234355 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Dec 13 01:33:26.236590 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Dec 13 01:33:26.239251 systemd[1]: systemd-resolved.service: Deactivated successfully. Dec 13 01:33:26.239370 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Dec 13 01:33:26.249895 systemd[1]: systemd-sysctl.service: Deactivated successfully. Dec 13 01:33:26.249969 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Dec 13 01:33:26.252139 systemd[1]: systemd-modules-load.service: Deactivated successfully. Dec 13 01:33:26.252212 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Dec 13 01:33:26.254371 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Dec 13 01:33:26.254432 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Dec 13 01:33:26.257174 systemd[1]: network-cleanup.service: Deactivated successfully. Dec 13 01:33:26.257316 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Dec 13 01:33:26.259382 systemd[1]: systemd-udevd.service: Deactivated successfully. Dec 13 01:33:26.259601 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Dec 13 01:33:26.262835 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Dec 13 01:33:26.262900 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Dec 13 01:33:26.264252 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Dec 13 01:33:26.264303 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Dec 13 01:33:26.266361 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Dec 13 01:33:26.266420 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Dec 13 01:33:26.268748 systemd[1]: dracut-cmdline.service: Deactivated successfully. Dec 13 01:33:26.268807 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Dec 13 01:33:26.270812 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Dec 13 01:33:26.270869 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Dec 13 01:33:26.285769 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Dec 13 01:33:26.286956 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Dec 13 01:33:26.287019 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Dec 13 01:33:26.289460 systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. Dec 13 01:33:26.289519 systemd[1]: Stopped systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Dec 13 01:33:26.291920 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Dec 13 01:33:26.291978 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Dec 13 01:33:26.294665 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Dec 13 01:33:26.294723 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:26.297676 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Dec 13 01:33:26.297801 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Dec 13 01:33:26.300615 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Dec 13 01:33:26.303247 systemd[1]: Starting initrd-switch-root.service - Switch Root... Dec 13 01:33:26.314678 systemd[1]: Switching root. Dec 13 01:33:26.346170 systemd-journald[193]: Journal stopped Dec 13 01:33:27.197897 systemd-journald[193]: Received SIGTERM from PID 1 (systemd). Dec 13 01:33:27.197968 kernel: SELinux: policy capability network_peer_controls=1 Dec 13 01:33:27.197983 kernel: SELinux: policy capability open_perms=1 Dec 13 01:33:27.197995 kernel: SELinux: policy capability extended_socket_class=1 Dec 13 01:33:27.198006 kernel: SELinux: policy capability always_check_network=0 Dec 13 01:33:27.198018 kernel: SELinux: policy capability cgroup_seclabel=1 Dec 13 01:33:27.198032 kernel: SELinux: policy capability nnp_nosuid_transition=1 Dec 13 01:33:27.198044 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Dec 13 01:33:27.198055 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Dec 13 01:33:27.198066 kernel: audit: type=1403 audit(1734053606.425:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Dec 13 01:33:27.198085 systemd[1]: Successfully loaded SELinux policy in 39.717ms. Dec 13 01:33:27.198104 systemd[1]: Relabeled /dev, /dev/shm, /run, /sys/fs/cgroup in 12.423ms. Dec 13 01:33:27.198117 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) Dec 13 01:33:27.198129 systemd[1]: Detected virtualization kvm. Dec 13 01:33:27.198149 systemd[1]: Detected architecture x86-64. Dec 13 01:33:27.198163 systemd[1]: Detected first boot. Dec 13 01:33:27.198175 systemd[1]: Initializing machine ID from VM UUID. Dec 13 01:33:27.198187 zram_generator::config[1059]: No configuration found. Dec 13 01:33:27.198201 systemd[1]: Populated /etc with preset unit settings. Dec 13 01:33:27.198213 systemd[1]: initrd-switch-root.service: Deactivated successfully. Dec 13 01:33:27.198227 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Dec 13 01:33:27.198244 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Dec 13 01:33:27.198259 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Dec 13 01:33:27.198276 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Dec 13 01:33:27.198290 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Dec 13 01:33:27.198306 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Dec 13 01:33:27.198319 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Dec 13 01:33:27.198330 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Dec 13 01:33:27.198345 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Dec 13 01:33:27.198363 systemd[1]: Created slice user.slice - User and Session Slice. Dec 13 01:33:27.198375 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Dec 13 01:33:27.198387 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Dec 13 01:33:27.198399 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Dec 13 01:33:27.198411 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Dec 13 01:33:27.198423 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Dec 13 01:33:27.198435 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Dec 13 01:33:27.198447 systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0... Dec 13 01:33:27.198461 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Dec 13 01:33:27.198474 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Dec 13 01:33:27.198485 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Dec 13 01:33:27.198497 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Dec 13 01:33:27.198509 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Dec 13 01:33:27.198521 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Dec 13 01:33:27.198533 systemd[1]: Reached target remote-fs.target - Remote File Systems. Dec 13 01:33:27.198549 systemd[1]: Reached target slices.target - Slice Units. Dec 13 01:33:27.198565 systemd[1]: Reached target swap.target - Swaps. Dec 13 01:33:27.198579 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Dec 13 01:33:27.198593 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Dec 13 01:33:27.198606 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Dec 13 01:33:27.198621 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Dec 13 01:33:27.198634 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Dec 13 01:33:27.198695 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Dec 13 01:33:27.198709 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Dec 13 01:33:27.198722 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Dec 13 01:33:27.198739 systemd[1]: Mounting media.mount - External Media Directory... Dec 13 01:33:27.198752 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:27.198766 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Dec 13 01:33:27.198780 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Dec 13 01:33:27.198794 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Dec 13 01:33:27.198808 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). Dec 13 01:33:27.198822 systemd[1]: Reached target machines.target - Containers. Dec 13 01:33:27.198835 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Dec 13 01:33:27.198852 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Dec 13 01:33:27.198865 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Dec 13 01:33:27.198879 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Dec 13 01:33:27.198893 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Dec 13 01:33:27.198908 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Dec 13 01:33:27.198921 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Dec 13 01:33:27.198935 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Dec 13 01:33:27.198949 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Dec 13 01:33:27.198962 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Dec 13 01:33:27.198978 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Dec 13 01:33:27.198993 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Dec 13 01:33:27.199006 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Dec 13 01:33:27.199020 systemd[1]: Stopped systemd-fsck-usr.service. Dec 13 01:33:27.199033 kernel: fuse: init (API version 7.39) Dec 13 01:33:27.199046 systemd[1]: Starting systemd-journald.service - Journal Service... Dec 13 01:33:27.199060 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Dec 13 01:33:27.199074 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Dec 13 01:33:27.199090 kernel: loop: module loaded Dec 13 01:33:27.199103 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Dec 13 01:33:27.199117 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Dec 13 01:33:27.199131 systemd[1]: verity-setup.service: Deactivated successfully. Dec 13 01:33:27.199153 systemd[1]: Stopped verity-setup.service. Dec 13 01:33:27.199167 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:27.199180 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Dec 13 01:33:27.199197 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Dec 13 01:33:27.199228 systemd[1]: Mounted media.mount - External Media Directory. Dec 13 01:33:27.199242 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Dec 13 01:33:27.199274 systemd-journald[1136]: Collecting audit messages is disabled. Dec 13 01:33:27.199297 kernel: ACPI: bus type drm_connector registered Dec 13 01:33:27.199311 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Dec 13 01:33:27.199328 systemd-journald[1136]: Journal started Dec 13 01:33:27.199353 systemd-journald[1136]: Runtime Journal (/run/log/journal/2d8f473ab1b44d0ca8f8198c9f67f72f) is 6.0M, max 48.3M, 42.2M free. Dec 13 01:33:26.928752 systemd[1]: Queued start job for default target multi-user.target. Dec 13 01:33:26.946560 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Dec 13 01:33:26.947009 systemd[1]: systemd-journald.service: Deactivated successfully. Dec 13 01:33:27.202698 systemd[1]: Started systemd-journald.service - Journal Service. Dec 13 01:33:27.204103 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Dec 13 01:33:27.205593 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Dec 13 01:33:27.207282 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Dec 13 01:33:27.209051 systemd[1]: modprobe@configfs.service: Deactivated successfully. Dec 13 01:33:27.209333 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Dec 13 01:33:27.211113 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Dec 13 01:33:27.211384 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Dec 13 01:33:27.213228 systemd[1]: modprobe@drm.service: Deactivated successfully. Dec 13 01:33:27.213487 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Dec 13 01:33:27.215297 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Dec 13 01:33:27.215499 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Dec 13 01:33:27.217112 systemd[1]: modprobe@fuse.service: Deactivated successfully. Dec 13 01:33:27.217298 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Dec 13 01:33:27.218753 systemd[1]: modprobe@loop.service: Deactivated successfully. Dec 13 01:33:27.218977 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Dec 13 01:33:27.220457 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Dec 13 01:33:27.222297 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Dec 13 01:33:27.223889 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Dec 13 01:33:27.240024 systemd[1]: Reached target network-pre.target - Preparation for Network. Dec 13 01:33:27.249774 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Dec 13 01:33:27.252421 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Dec 13 01:33:27.253598 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Dec 13 01:33:27.253624 systemd[1]: Reached target local-fs.target - Local File Systems. Dec 13 01:33:27.255705 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management (Varlink). Dec 13 01:33:27.258055 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Dec 13 01:33:27.264319 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Dec 13 01:33:27.265817 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Dec 13 01:33:27.277089 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Dec 13 01:33:27.282459 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Dec 13 01:33:27.283866 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Dec 13 01:33:27.286684 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Dec 13 01:33:27.287950 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Dec 13 01:33:27.292814 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Dec 13 01:33:27.299096 systemd-journald[1136]: Time spent on flushing to /var/log/journal/2d8f473ab1b44d0ca8f8198c9f67f72f is 24.272ms for 968 entries. Dec 13 01:33:27.299096 systemd-journald[1136]: System Journal (/var/log/journal/2d8f473ab1b44d0ca8f8198c9f67f72f) is 8.0M, max 195.6M, 187.6M free. Dec 13 01:33:27.341008 systemd-journald[1136]: Received client request to flush runtime journal. Dec 13 01:33:27.341064 kernel: loop0: detected capacity change from 0 to 140768 Dec 13 01:33:27.300791 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Dec 13 01:33:27.305796 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Dec 13 01:33:27.309362 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Dec 13 01:33:27.320466 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Dec 13 01:33:27.321956 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Dec 13 01:33:27.323832 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Dec 13 01:33:27.325676 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Dec 13 01:33:27.332510 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Dec 13 01:33:27.342868 systemd[1]: Starting systemd-machine-id-commit.service - Commit a transient machine-id on disk... Dec 13 01:33:27.347287 systemd[1]: Starting systemd-udev-settle.service - Wait for udev To Complete Device Initialization... Dec 13 01:33:27.349273 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Dec 13 01:33:27.350982 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Dec 13 01:33:27.360882 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Dec 13 01:33:27.363814 systemd-tmpfiles[1174]: ACLs are not supported, ignoring. Dec 13 01:33:27.364220 systemd-tmpfiles[1174]: ACLs are not supported, ignoring. Dec 13 01:33:27.366510 udevadm[1186]: systemd-udev-settle.service is deprecated. Please fix lvm2-activation-early.service, lvm2-activation.service not to pull it in. Dec 13 01:33:27.369665 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Dec 13 01:33:27.370955 systemd[1]: Finished systemd-machine-id-commit.service - Commit a transient machine-id on disk. Dec 13 01:33:27.373611 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Dec 13 01:33:27.382995 systemd[1]: Starting systemd-sysusers.service - Create System Users... Dec 13 01:33:27.554903 kernel: loop1: detected capacity change from 0 to 142488 Dec 13 01:33:27.583873 systemd[1]: Finished systemd-sysusers.service - Create System Users. Dec 13 01:33:27.595005 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Dec 13 01:33:27.598937 kernel: loop2: detected capacity change from 0 to 140768 Dec 13 01:33:27.621004 kernel: loop3: detected capacity change from 0 to 142488 Dec 13 01:33:27.630689 systemd-tmpfiles[1197]: ACLs are not supported, ignoring. Dec 13 01:33:27.630709 systemd-tmpfiles[1197]: ACLs are not supported, ignoring. Dec 13 01:33:27.634880 (sd-merge)[1198]: Using extensions 'containerd-flatcar', 'docker-flatcar'. Dec 13 01:33:27.635430 (sd-merge)[1198]: Merged extensions into '/usr'. Dec 13 01:33:27.637022 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Dec 13 01:33:27.639317 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Dec 13 01:33:27.650950 systemd[1]: Starting ensure-sysext.service... Dec 13 01:33:27.654988 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Dec 13 01:33:27.675878 systemd[1]: Reloading requested from client PID 1202 ('systemctl') (unit ensure-sysext.service)... Dec 13 01:33:27.675897 systemd[1]: Reloading... Dec 13 01:33:27.729488 systemd-tmpfiles[1203]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Dec 13 01:33:27.730062 systemd-tmpfiles[1203]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Dec 13 01:33:27.734287 systemd-tmpfiles[1203]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Dec 13 01:33:27.734882 systemd-tmpfiles[1203]: ACLs are not supported, ignoring. Dec 13 01:33:27.735066 systemd-tmpfiles[1203]: ACLs are not supported, ignoring. Dec 13 01:33:27.747692 systemd-tmpfiles[1203]: Detected autofs mount point /boot during canonicalization of boot. Dec 13 01:33:27.749862 systemd-tmpfiles[1203]: Skipping /boot Dec 13 01:33:27.824669 zram_generator::config[1227]: No configuration found. Dec 13 01:33:27.844622 systemd-tmpfiles[1203]: Detected autofs mount point /boot during canonicalization of boot. Dec 13 01:33:27.844649 systemd-tmpfiles[1203]: Skipping /boot Dec 13 01:33:27.981093 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. Dec 13 01:33:28.021909 ldconfig[1168]: /sbin/ldconfig: /lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Dec 13 01:33:28.031074 systemd[1]: Reloading finished in 354 ms. Dec 13 01:33:28.068833 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Dec 13 01:33:28.081272 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Dec 13 01:33:28.102171 systemd[1]: Starting audit-rules.service - Load Security Auditing Rules... Dec 13 01:33:28.105526 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Dec 13 01:33:28.111740 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Dec 13 01:33:28.118979 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Dec 13 01:33:28.123858 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Dec 13 01:33:28.129568 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.129944 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Dec 13 01:33:28.132802 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Dec 13 01:33:28.136481 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Dec 13 01:33:28.142309 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Dec 13 01:33:28.144411 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Dec 13 01:33:28.148970 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Dec 13 01:33:28.150411 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.152906 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Dec 13 01:33:28.153159 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Dec 13 01:33:28.155800 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Dec 13 01:33:28.156431 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Dec 13 01:33:28.166796 systemd[1]: modprobe@loop.service: Deactivated successfully. Dec 13 01:33:28.167006 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Dec 13 01:33:28.172193 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Dec 13 01:33:28.175746 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.176014 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Dec 13 01:33:28.184977 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Dec 13 01:33:28.188513 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Dec 13 01:33:28.191339 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Dec 13 01:33:28.192894 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Dec 13 01:33:28.193146 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.194349 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Dec 13 01:33:28.198261 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Dec 13 01:33:28.198455 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Dec 13 01:33:28.209392 systemd[1]: Started systemd-userdbd.service - User Database Manager. Dec 13 01:33:28.214332 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.214950 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Dec 13 01:33:28.221907 augenrules[1306]: No rules Dec 13 01:33:28.226971 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Dec 13 01:33:28.240328 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Dec 13 01:33:28.242375 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Dec 13 01:33:28.242878 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Dec 13 01:33:28.245122 systemd[1]: Finished audit-rules.service - Load Security Auditing Rules. Dec 13 01:33:28.247518 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Dec 13 01:33:28.249906 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Dec 13 01:33:28.250162 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Dec 13 01:33:28.252074 systemd[1]: modprobe@loop.service: Deactivated successfully. Dec 13 01:33:28.252329 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Dec 13 01:33:28.254088 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Dec 13 01:33:28.254335 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Dec 13 01:33:28.256149 systemd[1]: modprobe@drm.service: Deactivated successfully. Dec 13 01:33:28.256373 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Dec 13 01:33:28.264199 systemd[1]: Finished ensure-sysext.service. Dec 13 01:33:28.269689 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Dec 13 01:33:28.269757 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Dec 13 01:33:28.280919 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Dec 13 01:33:28.282160 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). Dec 13 01:33:28.289063 systemd-resolved[1273]: Positive Trust Anchors: Dec 13 01:33:28.289083 systemd-resolved[1273]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Dec 13 01:33:28.289124 systemd-resolved[1273]: 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 Dec 13 01:33:28.309246 systemd-resolved[1273]: Defaulting to hostname 'linux'. Dec 13 01:33:28.311859 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Dec 13 01:33:28.313349 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Dec 13 01:33:28.350819 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Dec 13 01:33:28.352803 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Dec 13 01:33:28.355256 systemd[1]: Reached target time-set.target - System Time Set. Dec 13 01:33:28.364938 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Dec 13 01:33:28.367746 systemd[1]: Starting systemd-update-done.service - Update is Completed... Dec 13 01:33:28.385298 systemd[1]: Finished systemd-update-done.service - Update is Completed. Dec 13 01:33:28.390957 systemd-udevd[1324]: Using default interface naming scheme 'v255'. Dec 13 01:33:28.408328 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Dec 13 01:33:28.423860 systemd[1]: Starting systemd-networkd.service - Network Configuration... Dec 13 01:33:28.454717 kernel: BTRFS info: devid 1 device path /dev/mapper/usr changed to /dev/dm-0 scanned by (udev-worker) (1338) Dec 13 01:33:28.457055 kernel: BTRFS info: devid 1 device path /dev/dm-0 changed to /dev/mapper/usr scanned by (udev-worker) (1338) Dec 13 01:33:28.460360 systemd[1]: Condition check resulted in dev-ttyS0.device - /dev/ttyS0 being skipped. Dec 13 01:33:28.469670 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 41 scanned by (udev-worker) (1330) Dec 13 01:33:28.494705 systemd-networkd[1334]: lo: Link UP Dec 13 01:33:28.494718 systemd-networkd[1334]: lo: Gained carrier Dec 13 01:33:28.496392 systemd-networkd[1334]: Enumeration completed Dec 13 01:33:28.496815 systemd-networkd[1334]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Dec 13 01:33:28.496820 systemd-networkd[1334]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Dec 13 01:33:28.497557 systemd[1]: Started systemd-networkd.service - Network Configuration. Dec 13 01:33:28.498908 systemd-networkd[1334]: eth0: Link UP Dec 13 01:33:28.498918 systemd-networkd[1334]: eth0: Gained carrier Dec 13 01:33:28.498930 systemd-networkd[1334]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Dec 13 01:33:28.499576 systemd[1]: Reached target network.target - Network. Dec 13 01:33:28.508866 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Dec 13 01:33:28.513207 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Dec 13 01:33:28.514722 systemd-networkd[1334]: eth0: DHCPv4 address 10.0.0.95/16, gateway 10.0.0.1 acquired from 10.0.0.1 Dec 13 01:33:28.515777 systemd-timesyncd[1321]: Network configuration changed, trying to establish connection. Dec 13 01:33:29.286784 systemd-resolved[1273]: Clock change detected. Flushing caches. Dec 13 01:33:29.287036 systemd-timesyncd[1321]: Contacted time server 10.0.0.1:123 (10.0.0.1). Dec 13 01:33:29.287091 systemd-timesyncd[1321]: Initial clock synchronization to Fri 2024-12-13 01:33:29.286750 UTC. Dec 13 01:33:29.289545 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input2 Dec 13 01:33:29.290704 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Dec 13 01:33:29.296574 kernel: ACPI: button: Power Button [PWRF] Dec 13 01:33:29.302697 kernel: i801_smbus 0000:00:1f.3: Enabling SMBus device Dec 13 01:33:29.303368 kernel: i801_smbus 0000:00:1f.3: SMBus using PCI interrupt Dec 13 01:33:29.306492 kernel: i2c i2c-0: 1/1 memory slots populated (from DMI) Dec 13 01:33:29.317630 kernel: i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD Dec 13 01:33:29.319998 kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3 Dec 13 01:33:29.309335 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Dec 13 01:33:29.389053 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:29.401540 kernel: mousedev: PS/2 mouse device common for all mice Dec 13 01:33:29.407674 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Dec 13 01:33:29.407915 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:29.428802 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Dec 13 01:33:29.506840 kernel: kvm_amd: TSC scaling supported Dec 13 01:33:29.506910 kernel: kvm_amd: Nested Virtualization enabled Dec 13 01:33:29.506924 kernel: kvm_amd: Nested Paging enabled Dec 13 01:33:29.507958 kernel: kvm_amd: LBR virtualization supported Dec 13 01:33:29.507985 kernel: kvm_amd: Virtual VMLOAD VMSAVE supported Dec 13 01:33:29.508602 kernel: kvm_amd: Virtual GIF supported Dec 13 01:33:29.531545 kernel: EDAC MC: Ver: 3.0.0 Dec 13 01:33:29.544767 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Dec 13 01:33:29.593092 systemd[1]: Finished systemd-udev-settle.service - Wait for udev To Complete Device Initialization. Dec 13 01:33:29.610666 systemd[1]: Starting lvm2-activation-early.service - Activation of LVM2 logical volumes... Dec 13 01:33:29.619584 lvm[1373]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Dec 13 01:33:29.653265 systemd[1]: Finished lvm2-activation-early.service - Activation of LVM2 logical volumes. Dec 13 01:33:29.655255 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Dec 13 01:33:29.656780 systemd[1]: Reached target sysinit.target - System Initialization. Dec 13 01:33:29.658274 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Dec 13 01:33:29.659852 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Dec 13 01:33:29.661759 systemd[1]: Started logrotate.timer - Daily rotation of log files. Dec 13 01:33:29.663316 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Dec 13 01:33:29.664785 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Dec 13 01:33:29.666348 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Dec 13 01:33:29.666391 systemd[1]: Reached target paths.target - Path Units. Dec 13 01:33:29.667596 systemd[1]: Reached target timers.target - Timer Units. Dec 13 01:33:29.670047 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Dec 13 01:33:29.673728 systemd[1]: Starting docker.socket - Docker Socket for the API... Dec 13 01:33:29.680416 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Dec 13 01:33:29.683456 systemd[1]: Starting lvm2-activation.service - Activation of LVM2 logical volumes... Dec 13 01:33:29.685496 systemd[1]: Listening on docker.socket - Docker Socket for the API. Dec 13 01:33:29.686993 systemd[1]: Reached target sockets.target - Socket Units. Dec 13 01:33:29.688255 systemd[1]: Reached target basic.target - Basic System. Dec 13 01:33:29.689458 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Dec 13 01:33:29.689483 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Dec 13 01:33:29.690751 systemd[1]: Starting containerd.service - containerd container runtime... Dec 13 01:33:29.693290 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Dec 13 01:33:29.693947 lvm[1377]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Dec 13 01:33:29.697810 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Dec 13 01:33:29.701670 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Dec 13 01:33:29.704150 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). Dec 13 01:33:29.706004 jq[1380]: false Dec 13 01:33:29.706435 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Dec 13 01:33:29.710551 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Dec 13 01:33:29.713485 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Dec 13 01:33:29.722760 systemd[1]: Starting systemd-logind.service - User Login Management... Dec 13 01:33:29.724968 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Dec 13 01:33:29.725657 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Dec 13 01:33:29.727761 systemd[1]: Starting update-engine.service - Update Engine... Dec 13 01:33:29.732249 dbus-daemon[1379]: [system] SELinux support is enabled Dec 13 01:33:29.732743 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Dec 13 01:33:29.735604 systemd[1]: Started dbus.service - D-Bus System Message Bus. Dec 13 01:33:29.739172 extend-filesystems[1381]: Found loop2 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found loop3 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found sr0 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda1 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda2 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda3 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found usr Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda4 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda6 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda7 Dec 13 01:33:29.740567 extend-filesystems[1381]: Found vda9 Dec 13 01:33:29.740567 extend-filesystems[1381]: Checking size of /dev/vda9 Dec 13 01:33:29.743178 systemd[1]: Finished lvm2-activation.service - Activation of LVM2 logical volumes. Dec 13 01:33:29.752809 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Dec 13 01:33:29.753126 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Dec 13 01:33:29.753601 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Dec 13 01:33:29.753873 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Dec 13 01:33:29.759884 extend-filesystems[1381]: Old size kept for /dev/vda9 Dec 13 01:33:29.759599 systemd[1]: extend-filesystems.service: Deactivated successfully. Dec 13 01:33:29.760900 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Dec 13 01:33:29.766122 systemd[1]: motdgen.service: Deactivated successfully. Dec 13 01:33:29.766742 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Dec 13 01:33:29.777563 jq[1392]: true Dec 13 01:33:29.781081 (ntainerd)[1402]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR Dec 13 01:33:29.786647 update_engine[1389]: I20241213 01:33:29.785367 1389 main.cc:92] Flatcar Update Engine starting Dec 13 01:33:29.791543 update_engine[1389]: I20241213 01:33:29.789196 1389 update_check_scheduler.cc:74] Next update check in 3m38s Dec 13 01:33:29.794554 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 41 scanned by (udev-worker) (1339) Dec 13 01:33:29.807011 jq[1407]: true Dec 13 01:33:29.831854 systemd-logind[1386]: Watching system buttons on /dev/input/event1 (Power Button) Dec 13 01:33:29.831886 systemd-logind[1386]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) Dec 13 01:33:29.832911 systemd[1]: Started update-engine.service - Update Engine. Dec 13 01:33:29.833255 systemd-logind[1386]: New seat seat0. Dec 13 01:33:29.838595 systemd[1]: Started systemd-logind.service - User Login Management. Dec 13 01:33:29.840740 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). Dec 13 01:33:29.840892 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Dec 13 01:33:29.843105 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). Dec 13 01:33:29.843215 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Dec 13 01:33:29.854822 systemd[1]: Started locksmithd.service - Cluster reboot manager. Dec 13 01:33:29.900703 bash[1428]: Updated "/home/core/.ssh/authorized_keys" Dec 13 01:33:29.869660 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Dec 13 01:33:29.898786 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Dec 13 01:33:29.920397 locksmithd[1429]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Dec 13 01:33:30.019288 sshd_keygen[1397]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Dec 13 01:33:30.042628 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Dec 13 01:33:30.054038 systemd[1]: Starting issuegen.service - Generate /run/issue... Dec 13 01:33:30.062177 systemd[1]: issuegen.service: Deactivated successfully. Dec 13 01:33:30.062464 systemd[1]: Finished issuegen.service - Generate /run/issue. Dec 13 01:33:30.065401 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Dec 13 01:33:30.101589 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Dec 13 01:33:30.112873 systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 13 01:33:30.115343 systemd[1]: Started serial-getty@ttyS0.service - Serial Getty on ttyS0. Dec 13 01:33:30.116805 systemd[1]: Reached target getty.target - Login Prompts. Dec 13 01:33:30.127323 containerd[1402]: time="2024-12-13T01:33:30.127234794Z" level=info msg="starting containerd" revision=174e0d1785eeda18dc2beba45e1d5a188771636b version=v1.7.21 Dec 13 01:33:30.183867 containerd[1402]: time="2024-12-13T01:33:30.183724262Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.aufs\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.185838 containerd[1402]: time="2024-12-13T01:33:30.185793593Z" 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.65-flatcar\\n\"): skip plugin" type=io.containerd.snapshotter.v1 Dec 13 01:33:30.185838 containerd[1402]: time="2024-12-13T01:33:30.185824100Z" level=info msg="loading plugin \"io.containerd.event.v1.exchange\"..." type=io.containerd.event.v1 Dec 13 01:33:30.185890 containerd[1402]: time="2024-12-13T01:33:30.185840310Z" level=info msg="loading plugin \"io.containerd.internal.v1.opt\"..." type=io.containerd.internal.v1 Dec 13 01:33:30.186101 containerd[1402]: time="2024-12-13T01:33:30.186071815Z" level=info msg="loading plugin \"io.containerd.warning.v1.deprecations\"..." type=io.containerd.warning.v1 Dec 13 01:33:30.186101 containerd[1402]: time="2024-12-13T01:33:30.186096050Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186200 containerd[1402]: time="2024-12-13T01:33:30.186170830Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." error="no scratch file generator: skip plugin" type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186200 containerd[1402]: time="2024-12-13T01:33:30.186190207Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186449 containerd[1402]: time="2024-12-13T01:33:30.186411001Z" 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 Dec 13 01:33:30.186473 containerd[1402]: time="2024-12-13T01:33:30.186454212Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186492 containerd[1402]: time="2024-12-13T01:33:30.186469621Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." error="devmapper not configured: skip plugin" type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186492 containerd[1402]: time="2024-12-13T01:33:30.186479489Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186636 containerd[1402]: time="2024-12-13T01:33:30.186608641Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.186891 containerd[1402]: time="2024-12-13T01:33:30.186864100Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.zfs\"..." type=io.containerd.snapshotter.v1 Dec 13 01:33:30.187028 containerd[1402]: time="2024-12-13T01:33:30.187000636Z" 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 Dec 13 01:33:30.187028 containerd[1402]: time="2024-12-13T01:33:30.187018029Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1 Dec 13 01:33:30.187168 containerd[1402]: time="2024-12-13T01:33:30.187141521Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1 Dec 13 01:33:30.187224 containerd[1402]: time="2024-12-13T01:33:30.187205651Z" level=info msg="metadata content store policy set" policy=shared Dec 13 01:33:30.193687 containerd[1402]: time="2024-12-13T01:33:30.193650197Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1 Dec 13 01:33:30.193735 containerd[1402]: time="2024-12-13T01:33:30.193701864Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1 Dec 13 01:33:30.193735 containerd[1402]: time="2024-12-13T01:33:30.193718164Z" level=info msg="loading plugin \"io.containerd.lease.v1.manager\"..." type=io.containerd.lease.v1 Dec 13 01:33:30.193772 containerd[1402]: time="2024-12-13T01:33:30.193750124Z" level=info msg="loading plugin \"io.containerd.streaming.v1.manager\"..." type=io.containerd.streaming.v1 Dec 13 01:33:30.193800 containerd[1402]: time="2024-12-13T01:33:30.193781753Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." type=io.containerd.runtime.v1 Dec 13 01:33:30.193992 containerd[1402]: time="2024-12-13T01:33:30.193963615Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." type=io.containerd.monitor.v1 Dec 13 01:33:30.194223 containerd[1402]: time="2024-12-13T01:33:30.194196241Z" level=info msg="loading plugin \"io.containerd.runtime.v2.task\"..." type=io.containerd.runtime.v2 Dec 13 01:33:30.194347 containerd[1402]: time="2024-12-13T01:33:30.194320484Z" level=info msg="loading plugin \"io.containerd.runtime.v2.shim\"..." type=io.containerd.runtime.v2 Dec 13 01:33:30.194347 containerd[1402]: time="2024-12-13T01:33:30.194340912Z" level=info msg="loading plugin \"io.containerd.sandbox.store.v1.local\"..." type=io.containerd.sandbox.store.v1 Dec 13 01:33:30.194385 containerd[1402]: time="2024-12-13T01:33:30.194355189Z" level=info msg="loading plugin \"io.containerd.sandbox.controller.v1.local\"..." type=io.containerd.sandbox.controller.v1 Dec 13 01:33:30.194385 containerd[1402]: time="2024-12-13T01:33:30.194368744Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194430 containerd[1402]: time="2024-12-13T01:33:30.194384995Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194430 containerd[1402]: time="2024-12-13T01:33:30.194400404Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194430 containerd[1402]: time="2024-12-13T01:33:30.194419309Z" level=info msg="loading plugin \"io.containerd.service.v1.images-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194480 containerd[1402]: time="2024-12-13T01:33:30.194434838Z" level=info msg="loading plugin \"io.containerd.service.v1.introspection-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194480 containerd[1402]: time="2024-12-13T01:33:30.194448123Z" level=info msg="loading plugin \"io.containerd.service.v1.namespaces-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194480 containerd[1402]: time="2024-12-13T01:33:30.194460757Z" level=info msg="loading plugin \"io.containerd.service.v1.snapshots-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194480 containerd[1402]: time="2024-12-13T01:33:30.194471818Z" level=info msg="loading plugin \"io.containerd.service.v1.tasks-service\"..." type=io.containerd.service.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194491575Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194505841Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194531319Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194544223Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194555434Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194567878Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194586 containerd[1402]: time="2024-12-13T01:33:30.194579760Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194613914Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194629463Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandbox-controllers\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194644582Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandboxes\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194656794Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194679858Z" level=info msg="loading plugin \"io.containerd.grpc.v1.streaming\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194694736Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194738 containerd[1402]: time="2024-12-13T01:33:30.194730453Z" level=info msg="loading plugin \"io.containerd.transfer.v1.local\"..." type=io.containerd.transfer.v1 Dec 13 01:33:30.194860 containerd[1402]: time="2024-12-13T01:33:30.194797318Z" level=info msg="loading plugin \"io.containerd.grpc.v1.transfer\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194860 containerd[1402]: time="2024-12-13T01:33:30.194818107Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194860 containerd[1402]: time="2024-12-13T01:33:30.194841010Z" level=info msg="loading plugin \"io.containerd.internal.v1.restart\"..." type=io.containerd.internal.v1 Dec 13 01:33:30.194911 containerd[1402]: time="2024-12-13T01:33:30.194894130Z" level=info msg="loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." type=io.containerd.tracing.processor.v1 Dec 13 01:33:30.194931 containerd[1402]: time="2024-12-13T01:33:30.194912394Z" 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 Dec 13 01:33:30.194931 containerd[1402]: time="2024-12-13T01:33:30.194922793Z" level=info msg="loading plugin \"io.containerd.internal.v1.tracing\"..." type=io.containerd.internal.v1 Dec 13 01:33:30.194987 containerd[1402]: time="2024-12-13T01:33:30.194933824Z" level=info msg="skip loading plugin \"io.containerd.internal.v1.tracing\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.internal.v1 Dec 13 01:33:30.194987 containerd[1402]: time="2024-12-13T01:33:30.194944324Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.194987 containerd[1402]: time="2024-12-13T01:33:30.194965814Z" level=info msg="loading plugin \"io.containerd.nri.v1.nri\"..." type=io.containerd.nri.v1 Dec 13 01:33:30.194987 containerd[1402]: time="2024-12-13T01:33:30.194975973Z" level=info msg="NRI interface is disabled by configuration." Dec 13 01:33:30.195056 containerd[1402]: time="2024-12-13T01:33:30.194989148Z" level=info msg="loading plugin \"io.containerd.grpc.v1.cri\"..." type=io.containerd.grpc.v1 Dec 13 01:33:30.195390 containerd[1402]: time="2024-12-13T01:33:30.195319317Z" 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}" Dec 13 01:33:30.195390 containerd[1402]: time="2024-12-13T01:33:30.195383938Z" level=info msg="Connect containerd service" Dec 13 01:33:30.195651 containerd[1402]: time="2024-12-13T01:33:30.195417481Z" level=info msg="using legacy CRI server" Dec 13 01:33:30.195651 containerd[1402]: time="2024-12-13T01:33:30.195424905Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Dec 13 01:33:30.196196 containerd[1402]: time="2024-12-13T01:33:30.195988592Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\"" Dec 13 01:33:30.197162 containerd[1402]: time="2024-12-13T01:33:30.197115105Z" 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" Dec 13 01:33:30.197335 containerd[1402]: time="2024-12-13T01:33:30.197282970Z" level=info msg="Start subscribing containerd event" Dec 13 01:33:30.197360 containerd[1402]: time="2024-12-13T01:33:30.197345877Z" level=info msg="Start recovering state" Dec 13 01:33:30.197444 containerd[1402]: time="2024-12-13T01:33:30.197420738Z" level=info msg="Start event monitor" Dec 13 01:33:30.197489 containerd[1402]: time="2024-12-13T01:33:30.197461855Z" level=info msg="Start snapshots syncer" Dec 13 01:33:30.197489 containerd[1402]: time="2024-12-13T01:33:30.197482233Z" level=info msg="Start cni network conf syncer for default" Dec 13 01:33:30.197543 containerd[1402]: time="2024-12-13T01:33:30.197494947Z" level=info msg="Start streaming server" Dec 13 01:33:30.197614 containerd[1402]: time="2024-12-13T01:33:30.197589354Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Dec 13 01:33:30.197682 containerd[1402]: time="2024-12-13T01:33:30.197657903Z" level=info msg=serving... address=/run/containerd/containerd.sock Dec 13 01:33:30.197759 containerd[1402]: time="2024-12-13T01:33:30.197734396Z" level=info msg="containerd successfully booted in 0.072096s" Dec 13 01:33:30.197834 systemd[1]: Started containerd.service - containerd container runtime. Dec 13 01:33:30.682759 systemd-networkd[1334]: eth0: Gained IPv6LL Dec 13 01:33:30.686657 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Dec 13 01:33:30.688398 systemd[1]: Reached target network-online.target - Network is Online. Dec 13 01:33:30.697733 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Dec 13 01:33:30.699832 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Dec 13 01:33:30.721501 systemd[1]: coreos-metadata.service: Deactivated successfully. Dec 13 01:33:30.721750 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Dec 13 01:33:30.724566 systemd[1]: Starting etcd-member.service - etcd (System Application Container)... Dec 13 01:33:30.725738 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Dec 13 01:33:30.726239 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Dec 13 01:33:30.729142 (-wrapper)[1475]: etcd-member.service: Referenced but unset environment variable evaluates to an empty string: ETCD_OPTS Dec 13 01:33:30.837761 systemd[1]: Starting docker.service - Docker Application Container Engine... Dec 13 01:33:30.839041 (dockerd)[1486]: 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 Dec 13 01:33:31.096597 dockerd[1486]: time="2024-12-13T01:33:31.096464676Z" level=info msg="Starting up" Dec 13 01:33:31.172226 systemd[1]: var-lib-docker-metacopy\x2dcheck4132802488-merged.mount: Deactivated successfully. Dec 13 01:33:31.198534 dockerd[1486]: time="2024-12-13T01:33:31.198460254Z" level=info msg="Loading containers: start." Dec 13 01:33:31.301551 kernel: Initializing XFRM netlink socket Dec 13 01:33:31.376969 systemd-networkd[1334]: docker0: Link UP Dec 13 01:33:31.398830 dockerd[1486]: time="2024-12-13T01:33:31.398789894Z" level=info msg="Loading containers: done." Dec 13 01:33:31.412001 systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck1905061880-merged.mount: Deactivated successfully. Dec 13 01:33:31.414928 dockerd[1486]: time="2024-12-13T01:33:31.414867565Z" 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 Dec 13 01:33:31.415039 dockerd[1486]: time="2024-12-13T01:33:31.415009692Z" level=info msg="Docker daemon" commit=061aa95809be396a6b5542618d8a34b02a21ff77 containerd-snapshotter=false storage-driver=overlay2 version=26.1.0 Dec 13 01:33:31.415175 dockerd[1486]: time="2024-12-13T01:33:31.415148823Z" level=info msg="Daemon has completed initialization" Dec 13 01:33:31.452868 dockerd[1486]: time="2024-12-13T01:33:31.452779534Z" level=info msg="API listen on /run/docker.sock" Dec 13 01:33:31.453215 systemd[1]: Started docker.service - Docker Application Container Engine. Dec 13 01:33:31.454434 etcd-wrapper[1480]: Error response from daemon: No such container: etcd-member Dec 13 01:33:31.469098 etcd-wrapper[1614]: Error response from daemon: No such container: etcd-member Dec 13 01:33:31.495335 etcd-wrapper[1633]: Unable to find image 'quay.io/coreos/etcd:v3.5.16' locally Dec 13 01:33:33.015923 etcd-wrapper[1633]: v3.5.16: Pulling from coreos/etcd Dec 13 01:33:33.599860 etcd-wrapper[1633]: 804c8aba2cc6: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 2ae710cd8bfe: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: d462aa345367: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 0f8b424aa0b9: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: d557676654e5: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: c8022d07192e: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: d858cbc252ad: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 1069fc2daed1: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: b40161cd83fc: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 5318d93a3a65: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 307c1adadb60: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: fbb01d9e9dc9: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: fbfea02ac3cf: Pulling fs layer Dec 13 01:33:33.599860 etcd-wrapper[1633]: 8c26e4bf18e2: Pulling fs layer Dec 13 01:33:33.600418 etcd-wrapper[1633]: 1e59a65f8816: Pulling fs layer Dec 13 01:33:33.600418 etcd-wrapper[1633]: 0f8b424aa0b9: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: ffbd4ca5f0bd: Pulling fs layer Dec 13 01:33:33.600418 etcd-wrapper[1633]: d557676654e5: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: c8022d07192e: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: d858cbc252ad: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: 1069fc2daed1: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: b40161cd83fc: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: 5318d93a3a65: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: 307c1adadb60: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: fbb01d9e9dc9: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: fbfea02ac3cf: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: 8c26e4bf18e2: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: 1e59a65f8816: Waiting Dec 13 01:33:33.600418 etcd-wrapper[1633]: ffbd4ca5f0bd: Waiting Dec 13 01:33:33.920106 etcd-wrapper[1633]: 804c8aba2cc6: Verifying Checksum Dec 13 01:33:33.920106 etcd-wrapper[1633]: 804c8aba2cc6: Download complete Dec 13 01:33:33.923579 etcd-wrapper[1633]: d462aa345367: Download complete Dec 13 01:33:34.303685 etcd-wrapper[1633]: 0f8b424aa0b9: Verifying Checksum Dec 13 01:33:34.303685 etcd-wrapper[1633]: 0f8b424aa0b9: Download complete Dec 13 01:33:34.507711 etcd-wrapper[1633]: 804c8aba2cc6: Pull complete Dec 13 01:33:34.718435 etcd-wrapper[1633]: c8022d07192e: Verifying Checksum Dec 13 01:33:34.718435 etcd-wrapper[1633]: c8022d07192e: Download complete Dec 13 01:33:34.950234 etcd-wrapper[1633]: 2ae710cd8bfe: Verifying Checksum Dec 13 01:33:34.950234 etcd-wrapper[1633]: 2ae710cd8bfe: Download complete Dec 13 01:33:34.971435 etcd-wrapper[1633]: d858cbc252ad: Verifying Checksum Dec 13 01:33:34.971435 etcd-wrapper[1633]: d858cbc252ad: Download complete Dec 13 01:33:35.304279 etcd-wrapper[1633]: d557676654e5: Verifying Checksum Dec 13 01:33:35.304279 etcd-wrapper[1633]: d557676654e5: Download complete Dec 13 01:33:35.383877 systemd[1]: var-lib-docker-overlay2-0d0df152f8d34c54c6db7dd061b8f066fa1ffd1953337ebda5c1109a6c824085-merged.mount: Deactivated successfully. Dec 13 01:33:35.415240 etcd-wrapper[1633]: 1069fc2daed1: Verifying Checksum Dec 13 01:33:35.415344 etcd-wrapper[1633]: 1069fc2daed1: Download complete Dec 13 01:33:35.422967 etcd-wrapper[1633]: b40161cd83fc: Download complete Dec 13 01:33:35.559745 etcd-wrapper[1633]: 2ae710cd8bfe: Pull complete Dec 13 01:33:35.568702 etcd-wrapper[1633]: 5318d93a3a65: Verifying Checksum Dec 13 01:33:35.568702 etcd-wrapper[1633]: 5318d93a3a65: Download complete Dec 13 01:33:35.650678 etcd-wrapper[1633]: 307c1adadb60: Verifying Checksum Dec 13 01:33:35.650678 etcd-wrapper[1633]: 307c1adadb60: Download complete Dec 13 01:33:35.797556 etcd-wrapper[1633]: fbb01d9e9dc9: Verifying Checksum Dec 13 01:33:35.797556 etcd-wrapper[1633]: fbb01d9e9dc9: Download complete Dec 13 01:33:35.941276 etcd-wrapper[1633]: 8c26e4bf18e2: Verifying Checksum Dec 13 01:33:35.941276 etcd-wrapper[1633]: 8c26e4bf18e2: Download complete Dec 13 01:33:35.967377 systemd[1]: var-lib-docker-overlay2-1bde241ce92932336515287d00d5c0b0b4bbb05f9456d0a5124f57ce1ead7006-merged.mount: Deactivated successfully. Dec 13 01:33:36.324765 etcd-wrapper[1633]: 1e59a65f8816: Verifying Checksum Dec 13 01:33:36.324765 etcd-wrapper[1633]: 1e59a65f8816: Download complete Dec 13 01:33:36.324765 etcd-wrapper[1633]: ffbd4ca5f0bd: Verifying Checksum Dec 13 01:33:36.324765 etcd-wrapper[1633]: ffbd4ca5f0bd: Download complete Dec 13 01:33:36.360824 etcd-wrapper[1633]: fbfea02ac3cf: Download complete Dec 13 01:33:37.111361 etcd-wrapper[1633]: d462aa345367: Pull complete Dec 13 01:33:37.151045 systemd[1]: var-lib-docker-overlay2-aba7c98711f191f3d830cba71440886473dc70385d7404cc7c2a324bd12c79d6-merged.mount: Deactivated successfully. Dec 13 01:33:37.184635 etcd-wrapper[1633]: 0f8b424aa0b9: Pull complete Dec 13 01:33:37.205652 systemd[1]: var-lib-docker-overlay2-2b13100464ae053069d00c5b50c34329add1f6d7a5d9db1f9241279698d8ac02-merged.mount: Deactivated successfully. Dec 13 01:33:37.223812 etcd-wrapper[1633]: d557676654e5: Pull complete Dec 13 01:33:37.256477 etcd-wrapper[1633]: c8022d07192e: Pull complete Dec 13 01:33:37.285336 etcd-wrapper[1633]: d858cbc252ad: Pull complete Dec 13 01:33:37.314817 etcd-wrapper[1633]: 1069fc2daed1: Pull complete Dec 13 01:33:37.344798 etcd-wrapper[1633]: b40161cd83fc: Pull complete Dec 13 01:33:37.564054 etcd-wrapper[1633]: 5318d93a3a65: Pull complete Dec 13 01:33:37.591979 etcd-wrapper[1633]: 307c1adadb60: Pull complete Dec 13 01:33:37.798421 etcd-wrapper[1633]: fbb01d9e9dc9: Pull complete Dec 13 01:33:37.943007 etcd-wrapper[1633]: fbfea02ac3cf: Pull complete Dec 13 01:33:38.095828 etcd-wrapper[1633]: 8c26e4bf18e2: Pull complete Dec 13 01:33:38.118674 etcd-wrapper[1633]: 1e59a65f8816: Pull complete Dec 13 01:33:38.140994 etcd-wrapper[1633]: ffbd4ca5f0bd: Pull complete Dec 13 01:33:38.148568 systemd[1]: var-lib-docker-overlay2-d71b079f9f47b5807c50bcf8b634e1268f199070ff085240c878e6c42ce478fa-merged.mount: Deactivated successfully. Dec 13 01:33:38.151463 etcd-wrapper[1633]: Digest: sha256:d967d98a12dc220a1a290794711dba7eba04b8ce465e12b02383d1bfbb33e159 Dec 13 01:33:38.155988 etcd-wrapper[1633]: Status: Downloaded newer image for quay.io/coreos/etcd:v3.5.16 Dec 13 01:33:38.167638 systemd[1]: var-lib-docker-overlay2-8bebd7466104d8d98963170f7fe30614d533b8f4af8ad6e7b55174f12fdd0611\x2dinit-merged.mount: Deactivated successfully. Dec 13 01:33:38.180275 systemd[1]: var-lib-docker-overlay2-8bebd7466104d8d98963170f7fe30614d533b8f4af8ad6e7b55174f12fdd0611-merged.mount: Deactivated successfully. Dec 13 01:33:38.299822 containerd[1402]: time="2024-12-13T01:33:38.299605216Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Dec 13 01:33:38.299822 containerd[1402]: time="2024-12-13T01:33:38.299734037Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Dec 13 01:33:38.299822 containerd[1402]: time="2024-12-13T01:33:38.299773762Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Dec 13 01:33:38.300274 containerd[1402]: time="2024-12-13T01:33:38.299946075Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Dec 13 01:33:38.320735 systemd[1]: Started docker-6b70d6475d8903f3ac85dd11962497d7a0e6fcd68c42c8dc4e51b7b32fb559c1.scope - libcontainer container 6b70d6475d8903f3ac85dd11962497d7a0e6fcd68c42c8dc4e51b7b32fb559c1. Dec 13 01:33:38.334568 systemd-resolved[1273]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.368143Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_DATA_DIR","variable-value":"/var/lib/etcd"} Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.368256Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_NAME","variable-value":"2d8f473ab1b44d0ca8f8198c9f67f72f"} Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368283Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_URL=quay.io/coreos/etcd"} Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368291Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_TAG=v3.5.16"} Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368298Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_USER=etcd"} Dec 13 01:33:38.368402 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368303Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_SSL_DIR=/etc/ssl/certs"} Dec 13 01:33:38.368928 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368321Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Dec 13 01:33:38.368928 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.368403Z","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.95:2379"]} Dec 13 01:33:38.368928 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.368476Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Dec 13 01:33:38.368928 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.368505Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} Dec 13 01:33:38.369089 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.368987Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} Dec 13 01:33:38.369280 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.369131Z","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":"2d8f473ab1b44d0ca8f8198c9f67f72f","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.95:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"2d8f473ab1b44d0ca8f8198c9f67f72f=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"} Dec 13 01:33:38.371990 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.371850Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"2.374202ms"} Dec 13 01:33:38.375770 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375596Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} Dec 13 01:33:38.375873 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375700Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} Dec 13 01:33:38.375873 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375777Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} Dec 13 01:33:38.376005 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375804Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} Dec 13 01:33:38.376005 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375825Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} Dec 13 01:33:38.376005 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.375903Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Dec 13 01:33:38.380579 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:33:38.380428Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} Dec 13 01:33:38.381451 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.381283Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} Dec 13 01:33:38.382409 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.382282Z","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"} Dec 13 01:33:38.383351 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383061Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} Dec 13 01:33:38.383545 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383205Z","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"} Dec 13 01:33:38.383545 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383231Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Dec 13 01:33:38.383545 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383263Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} Dec 13 01:33:38.383545 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383285Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} Dec 13 01:33:38.383545 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.383293Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} Dec 13 01:33:38.385013 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.384198Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Dec 13 01:33:38.385449 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.385117Z","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"]} Dec 13 01:33:38.385595 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.385399Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} Dec 13 01:33:38.385595 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.385407Z","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.95:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} Dec 13 01:33:38.385595 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.385411Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976385Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976445Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976466Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976480Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976486Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976495Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} Dec 13 01:33:38.976818 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.976506Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} Dec 13 01:33:38.977651 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.977433Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} Dec 13 01:33:38.978331 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978019Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:2d8f473ab1b44d0ca8f8198c9f67f72f ClientURLs:[http://10.0.0.95:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} Dec 13 01:33:38.978331 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978027Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} Dec 13 01:33:38.978419 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978196Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} Dec 13 01:33:38.978419 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978307Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} Dec 13 01:33:38.978739 systemd[1]: Started etcd-member.service - etcd (System Application Container). Dec 13 01:33:38.978847 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978426Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} Dec 13 01:33:38.978847 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978539Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} Dec 13 01:33:38.978847 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978568Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} Dec 13 01:33:38.978847 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.978685Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Dec 13 01:33:38.979650 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:33:38.979114Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} Dec 13 01:33:38.979537 systemd[1]: Reached target multi-user.target - Multi-User System. Dec 13 01:33:38.979721 systemd[1]: Startup finished in 672ms (kernel) + 3.729s (initrd) + 11.821s (userspace) = 16.224s. Dec 13 01:33:39.534887 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Dec 13 01:33:39.536309 systemd[1]: Started sshd@0-10.0.0.95:22-10.0.0.1:52150.service - OpenSSH per-connection server daemon (10.0.0.1:52150). Dec 13 01:33:39.592903 sshd[1778]: Accepted publickey for core from 10.0.0.1 port 52150 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:39.595305 sshd[1778]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:39.606946 systemd-logind[1386]: New session 1 of user core. Dec 13 01:33:39.608510 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Dec 13 01:33:39.618991 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Dec 13 01:33:39.632775 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Dec 13 01:33:39.650069 systemd[1]: Starting user@500.service - User Manager for UID 500... Dec 13 01:33:39.655258 (systemd)[1782]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Dec 13 01:33:39.787645 systemd[1782]: Queued start job for default target default.target. Dec 13 01:33:39.807056 systemd[1782]: Created slice app.slice - User Application Slice. Dec 13 01:33:39.807086 systemd[1782]: Reached target paths.target - Paths. Dec 13 01:33:39.807100 systemd[1782]: Reached target timers.target - Timers. Dec 13 01:33:39.808775 systemd[1782]: Starting dbus.socket - D-Bus User Message Bus Socket... Dec 13 01:33:39.821184 systemd[1782]: Listening on dbus.socket - D-Bus User Message Bus Socket. Dec 13 01:33:39.821333 systemd[1782]: Reached target sockets.target - Sockets. Dec 13 01:33:39.821353 systemd[1782]: Reached target basic.target - Basic System. Dec 13 01:33:39.821397 systemd[1782]: Reached target default.target - Main User Target. Dec 13 01:33:39.821435 systemd[1782]: Startup finished in 156ms. Dec 13 01:33:39.822235 systemd[1]: Started user@500.service - User Manager for UID 500. Dec 13 01:33:39.824098 systemd[1]: Started session-1.scope - Session 1 of User core. Dec 13 01:33:39.900914 systemd[1]: Started sshd@1-10.0.0.95:22-10.0.0.1:52164.service - OpenSSH per-connection server daemon (10.0.0.1:52164). Dec 13 01:33:39.941603 sshd[1793]: Accepted publickey for core from 10.0.0.1 port 52164 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:39.943792 sshd[1793]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:39.949240 systemd-logind[1386]: New session 2 of user core. Dec 13 01:33:39.958835 systemd[1]: Started session-2.scope - Session 2 of User core. Dec 13 01:33:40.015334 sshd[1793]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.027828 systemd[1]: sshd@1-10.0.0.95:22-10.0.0.1:52164.service: Deactivated successfully. Dec 13 01:33:40.029694 systemd[1]: session-2.scope: Deactivated successfully. Dec 13 01:33:40.031725 systemd-logind[1386]: Session 2 logged out. Waiting for processes to exit. Dec 13 01:33:40.041770 systemd[1]: Started sshd@2-10.0.0.95:22-10.0.0.1:52166.service - OpenSSH per-connection server daemon (10.0.0.1:52166). Dec 13 01:33:40.042763 systemd-logind[1386]: Removed session 2. Dec 13 01:33:40.082125 sshd[1800]: Accepted publickey for core from 10.0.0.1 port 52166 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.084311 sshd[1800]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.089508 systemd-logind[1386]: New session 3 of user core. Dec 13 01:33:40.098888 systemd[1]: Started session-3.scope - Session 3 of User core. Dec 13 01:33:40.150072 sshd[1800]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.170095 systemd[1]: sshd@2-10.0.0.95:22-10.0.0.1:52166.service: Deactivated successfully. Dec 13 01:33:40.172237 systemd[1]: session-3.scope: Deactivated successfully. Dec 13 01:33:40.173865 systemd-logind[1386]: Session 3 logged out. Waiting for processes to exit. Dec 13 01:33:40.175404 systemd[1]: Started sshd@3-10.0.0.95:22-10.0.0.1:52170.service - OpenSSH per-connection server daemon (10.0.0.1:52170). Dec 13 01:33:40.176747 systemd-logind[1386]: Removed session 3. Dec 13 01:33:40.233489 sshd[1807]: Accepted publickey for core from 10.0.0.1 port 52170 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.235381 sshd[1807]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.240050 systemd-logind[1386]: New session 4 of user core. Dec 13 01:33:40.249800 systemd[1]: Started session-4.scope - Session 4 of User core. Dec 13 01:33:40.308303 sshd[1807]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.327899 systemd[1]: sshd@3-10.0.0.95:22-10.0.0.1:52170.service: Deactivated successfully. Dec 13 01:33:40.330120 systemd[1]: session-4.scope: Deactivated successfully. Dec 13 01:33:40.332256 systemd-logind[1386]: Session 4 logged out. Waiting for processes to exit. Dec 13 01:33:40.340096 systemd[1]: Started sshd@4-10.0.0.95:22-10.0.0.1:52182.service - OpenSSH per-connection server daemon (10.0.0.1:52182). Dec 13 01:33:40.341089 systemd-logind[1386]: Removed session 4. Dec 13 01:33:40.381040 sshd[1814]: Accepted publickey for core from 10.0.0.1 port 52182 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.382709 sshd[1814]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.387312 systemd-logind[1386]: New session 5 of user core. Dec 13 01:33:40.401833 systemd[1]: Started session-5.scope - Session 5 of User core. Dec 13 01:33:40.463373 sudo[1817]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/setenforce 1 Dec 13 01:33:40.463833 sudo[1817]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Dec 13 01:33:40.486349 sudo[1817]: pam_unix(sudo:session): session closed for user root Dec 13 01:33:40.489030 sshd[1814]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.503271 systemd[1]: sshd@4-10.0.0.95:22-10.0.0.1:52182.service: Deactivated successfully. Dec 13 01:33:40.505642 systemd[1]: session-5.scope: Deactivated successfully. Dec 13 01:33:40.507591 systemd-logind[1386]: Session 5 logged out. Waiting for processes to exit. Dec 13 01:33:40.509255 systemd[1]: Started sshd@5-10.0.0.95:22-10.0.0.1:52188.service - OpenSSH per-connection server daemon (10.0.0.1:52188). Dec 13 01:33:40.511021 systemd-logind[1386]: Removed session 5. Dec 13 01:33:40.555842 sshd[1822]: Accepted publickey for core from 10.0.0.1 port 52188 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.557627 sshd[1822]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.562101 systemd-logind[1386]: New session 6 of user core. Dec 13 01:33:40.579855 systemd[1]: Started session-6.scope - Session 6 of User core. Dec 13 01:33:40.637098 sudo[1826]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/bin/rm -rf /etc/audit/rules.d/80-selinux.rules /etc/audit/rules.d/99-default.rules Dec 13 01:33:40.637583 sudo[1826]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Dec 13 01:33:40.642114 sudo[1826]: pam_unix(sudo:session): session closed for user root Dec 13 01:33:40.650227 sudo[1825]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/bin/systemctl restart audit-rules Dec 13 01:33:40.650706 sudo[1825]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Dec 13 01:33:40.668792 systemd[1]: Stopping audit-rules.service - Load Security Auditing Rules... Dec 13 01:33:40.671524 auditctl[1829]: No rules Dec 13 01:33:40.672122 systemd[1]: audit-rules.service: Deactivated successfully. Dec 13 01:33:40.672458 systemd[1]: Stopped audit-rules.service - Load Security Auditing Rules. Dec 13 01:33:40.675752 systemd[1]: Starting audit-rules.service - Load Security Auditing Rules... Dec 13 01:33:40.714795 augenrules[1847]: No rules Dec 13 01:33:40.716727 systemd[1]: Finished audit-rules.service - Load Security Auditing Rules. Dec 13 01:33:40.718068 sudo[1825]: pam_unix(sudo:session): session closed for user root Dec 13 01:33:40.720099 sshd[1822]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.732284 systemd[1]: sshd@5-10.0.0.95:22-10.0.0.1:52188.service: Deactivated successfully. Dec 13 01:33:40.734725 systemd[1]: session-6.scope: Deactivated successfully. Dec 13 01:33:40.736372 systemd-logind[1386]: Session 6 logged out. Waiting for processes to exit. Dec 13 01:33:40.752874 systemd[1]: Started sshd@6-10.0.0.95:22-10.0.0.1:52198.service - OpenSSH per-connection server daemon (10.0.0.1:52198). Dec 13 01:33:40.754036 systemd-logind[1386]: Removed session 6. Dec 13 01:33:40.789120 sshd[1855]: Accepted publickey for core from 10.0.0.1 port 52198 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.790780 sshd[1855]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.794934 systemd-logind[1386]: New session 7 of user core. Dec 13 01:33:40.804674 systemd[1]: Started session-7.scope - Session 7 of User core. Dec 13 01:33:40.855937 sshd[1855]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:40.865140 systemd[1]: sshd@6-10.0.0.95:22-10.0.0.1:52198.service: Deactivated successfully. Dec 13 01:33:40.867830 systemd[1]: session-7.scope: Deactivated successfully. Dec 13 01:33:40.869968 systemd-logind[1386]: Session 7 logged out. Waiting for processes to exit. Dec 13 01:33:40.871652 systemd[1]: Started sshd@7-10.0.0.95:22-10.0.0.1:52214.service - OpenSSH per-connection server daemon (10.0.0.1:52214). Dec 13 01:33:40.872632 systemd-logind[1386]: Removed session 7. Dec 13 01:33:40.933058 sshd[1864]: Accepted publickey for core from 10.0.0.1 port 52214 ssh2: RSA SHA256:x0r+OYSWSaRwllGtX4o4H8bWGnkqZzK3ZUwKdtfgOO0 Dec 13 01:33:40.934986 sshd[1864]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Dec 13 01:33:40.939533 systemd-logind[1386]: New session 8 of user core. Dec 13 01:33:40.949694 systemd[1]: Started session-8.scope - Session 8 of User core. Dec 13 01:33:41.409079 sshd[1864]: pam_unix(sshd:session): session closed for user core Dec 13 01:33:41.415320 systemd[1]: sshd@7-10.0.0.95:22-10.0.0.1:52214.service: Deactivated successfully. Dec 13 01:33:41.418073 systemd[1]: session-8.scope: Deactivated successfully. Dec 13 01:33:41.418858 systemd-logind[1386]: Session 8 logged out. Waiting for processes to exit. Dec 13 01:33:41.420296 systemd-logind[1386]: Removed session 8. Dec 13 01:34:14.789946 update_engine[1389]: I20241213 01:34:14.789835 1389 update_attempter.cc:509] Updating boot flags... Dec 13 01:34:14.840549 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 41 scanned by (udev-worker) (1883) Dec 13 01:34:14.873594 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 41 scanned by (udev-worker) (1884) Dec 13 01:34:50.659074 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:50.658752Z","caller":"traceutil/trace.go:171","msg":"trace[956383259] transaction","detail":"{read_only:false; response_revision:215; number_of_response:1; }","duration":"172.160432ms","start":"2024-12-13T01:34:50.486574Z","end":"2024-12-13T01:34:50.658735Z","steps":["trace[956383259] 'process raft request' (duration: 96.169228ms)","trace[956383259] 'compare' (duration: 75.945548ms)"],"step_count":2} Dec 13 01:34:52.874120 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:52.873684Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.51098ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Dec 13 01:34:52.874120 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:52.873779Z","caller":"traceutil/trace.go:171","msg":"trace[1778054276] linearizableReadLoop","detail":"{readStateIndex:318; appliedIndex:317; }","duration":"124.974903ms","start":"2024-12-13T01:34:52.748791Z","end":"2024-12-13T01:34:52.873766Z","steps":["trace[1778054276] 'read index received' (duration: 7.885445ms)","trace[1778054276] 'applied index is now lower than readState.Index' (duration: 117.088486ms)"],"step_count":2} Dec 13 01:34:52.874120 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:52.873821Z","caller":"traceutil/trace.go:171","msg":"trace[511443394] transaction","detail":"{read_only:false; response_revision:309; number_of_response:1; }","duration":"127.735316ms","start":"2024-12-13T01:34:52.746072Z","end":"2024-12-13T01:34:52.873807Z","steps":["trace[511443394] 'compare' (duration: 116.380275ms)"],"step_count":1} Dec 13 01:34:52.874120 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:52.873843Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"125.044914ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/generic-garbage-collector\" ","response":"range_response_count:1 size:216"} Dec 13 01:34:52.874878 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:52.873861Z","caller":"traceutil/trace.go:171","msg":"trace[1582274497] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/generic-garbage-collector; range_end:; response_count:1; response_revision:309; }","duration":"125.067607ms","start":"2024-12-13T01:34:52.748787Z","end":"2024-12-13T01:34:52.873855Z","steps":["trace[1582274497] 'agreement among raft nodes before linearized reading' (duration: 125.012173ms)"],"step_count":1} Dec 13 01:34:53.809957 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:53.809589Z","caller":"traceutil/trace.go:171","msg":"trace[1322964073] linearizableReadLoop","detail":"{readStateIndex:360; appliedIndex:359; }","duration":"107.465452ms","start":"2024-12-13T01:34:53.702098Z","end":"2024-12-13T01:34:53.809563Z","steps":["trace[1322964073] 'read index received' (duration: 51.52188ms)","trace[1322964073] 'applied index is now lower than readState.Index' (duration: 55.9428ms)"],"step_count":2} Dec 13 01:34:53.809957 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:53.809656Z","caller":"traceutil/trace.go:171","msg":"trace[1866356009] transaction","detail":"{read_only:false; response_revision:350; number_of_response:1; }","duration":"150.830789ms","start":"2024-12-13T01:34:53.658805Z","end":"2024-12-13T01:34:53.809636Z","steps":["trace[1866356009] 'process raft request' (duration: 94.849446ms)","trace[1866356009] 'compare' (duration: 55.72442ms)"],"step_count":2} Dec 13 01:34:53.809957 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:53.809794Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"107.670626ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/kube-system\" ","response":"range_response_count:1 size:351"} Dec 13 01:34:53.810363 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:53.809884Z","caller":"traceutil/trace.go:171","msg":"trace[871033230] range","detail":"{range_begin:/registry/namespaces/kube-system; range_end:; response_count:1; response_revision:350; }","duration":"107.792455ms","start":"2024-12-13T01:34:53.702072Z","end":"2024-12-13T01:34:53.809864Z","steps":["trace[871033230] 'agreement among raft nodes before linearized reading' (duration: 107.581649ms)"],"step_count":1} Dec 13 01:34:54.077407 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.076891Z","caller":"traceutil/trace.go:171","msg":"trace[372910315] transaction","detail":"{read_only:false; response_revision:363; number_of_response:1; }","duration":"114.178075ms","start":"2024-12-13T01:34:53.962694Z","end":"2024-12-13T01:34:54.076872Z","steps":["trace[372910315] 'process raft request' (duration: 76.725885ms)","trace[372910315] 'compare' (duration: 37.305696ms)"],"step_count":2} Dec 13 01:34:54.077407 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.076920Z","caller":"traceutil/trace.go:171","msg":"trace[362792576] transaction","detail":"{read_only:false; response_revision:364; number_of_response:1; }","duration":"110.532361ms","start":"2024-12-13T01:34:53.966373Z","end":"2024-12-13T01:34:54.076906Z","steps":["trace[362792576] 'process raft request' (duration: 110.45184ms)"],"step_count":1} Dec 13 01:34:54.500013 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:54.499430Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"109.698369ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Dec 13 01:34:54.500013 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.499641Z","caller":"traceutil/trace.go:171","msg":"trace[1114847483] transaction","detail":"{read_only:false; number_of_response:1; response_revision:392; }","duration":"276.894691ms","start":"2024-12-13T01:34:54.222733Z","end":"2024-12-13T01:34:54.499628Z","steps":["trace[1114847483] 'process raft request' (duration: 276.772291ms)"],"step_count":1} Dec 13 01:34:54.500013 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.499651Z","caller":"traceutil/trace.go:171","msg":"trace[1159768156] transaction","detail":"{read_only:false; response_revision:392; number_of_response:1; }","duration":"277.879791ms","start":"2024-12-13T01:34:54.221748Z","end":"2024-12-13T01:34:54.499627Z","steps":["trace[1159768156] 'process raft request' (duration: 167.820293ms)","trace[1159768156] 'compare' (duration: 109.610685ms)"],"step_count":2} Dec 13 01:34:54.523239 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.522936Z","caller":"traceutil/trace.go:171","msg":"trace[751539190] linearizableReadLoop","detail":"{readStateIndex:404; appliedIndex:401; }","duration":"274.119822ms","start":"2024-12-13T01:34:54.248799Z","end":"2024-12-13T01:34:54.522918Z","steps":["trace[751539190] 'read index received' (duration: 140.835775ms)","trace[751539190] 'applied index is now lower than readState.Index' (duration: 133.283426ms)"],"step_count":2} Dec 13 01:34:54.523239 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.522962Z","caller":"traceutil/trace.go:171","msg":"trace[644074599] transaction","detail":"{read_only:false; response_revision:393; number_of_response:1; }","duration":"287.252997ms","start":"2024-12-13T01:34:54.235694Z","end":"2024-12-13T01:34:54.522947Z","steps":["trace[644074599] 'process raft request' (duration: 287.14778ms)"],"step_count":1} Dec 13 01:34:54.523239 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:54.523035Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"274.225791ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/kube-system\" ","response":"range_response_count:1 size:351"} Dec 13 01:34:54.523239 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.523059Z","caller":"traceutil/trace.go:171","msg":"trace[896212967] range","detail":"{range_begin:/registry/namespaces/kube-system; range_end:; response_count:1; response_revision:393; }","duration":"274.2789ms","start":"2024-12-13T01:34:54.248772Z","end":"2024-12-13T01:34:54.523051Z","steps":["trace[896212967] 'agreement among raft nodes before linearized reading' (duration: 274.212105ms)"],"step_count":1} Dec 13 01:34:54.542005 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:34:54.541691Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"185.534017ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/kube-scheduler-localhost.181098a5698f3944\" ","response":"range_response_count:1 size:817"} Dec 13 01:34:54.542005 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:34:54.541754Z","caller":"traceutil/trace.go:171","msg":"trace[1823569118] range","detail":"{range_begin:/registry/events/kube-system/kube-scheduler-localhost.181098a5698f3944; range_end:; response_count:1; response_revision:394; }","duration":"185.627362ms","start":"2024-12-13T01:34:54.356111Z","end":"2024-12-13T01:34:54.541739Z","steps":["trace[1823569118] 'agreement among raft nodes before linearized reading' (duration: 185.525922ms)"],"step_count":1} Dec 13 01:35:01.417849 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:01.417382Z","caller":"traceutil/trace.go:171","msg":"trace[1700887334] transaction","detail":"{read_only:false; response_revision:511; number_of_response:1; }","duration":"101.487622ms","start":"2024-12-13T01:35:01.315865Z","end":"2024-12-13T01:35:01.417353Z","steps":["trace[1700887334] 'process raft request' (duration: 81.082838ms)","trace[1700887334] 'compare' (duration: 20.217893ms)"],"step_count":2} Dec 13 01:35:03.620025 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.619621Z","caller":"traceutil/trace.go:171","msg":"trace[1202878668] linearizableReadLoop","detail":"{readStateIndex:620; appliedIndex:617; }","duration":"195.791556ms","start":"2024-12-13T01:35:03.423808Z","end":"2024-12-13T01:35:03.619599Z","steps":["trace[1202878668] 'read index received' (duration: 11.962187ms)","trace[1202878668] 'applied index is now lower than readState.Index' (duration: 183.828678ms)"],"step_count":2} Dec 13 01:35:03.620025 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.619676Z","caller":"traceutil/trace.go:171","msg":"trace[221466890] transaction","detail":"{read_only:false; response_revision:605; number_of_response:1; }","duration":"205.266466ms","start":"2024-12-13T01:35:03.414388Z","end":"2024-12-13T01:35:03.619654Z","steps":["trace[221466890] 'process raft request' (duration: 179.250017ms)","trace[221466890] 'compare' (duration: 25.757883ms)"],"step_count":2} Dec 13 01:35:03.620025 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.619682Z","caller":"traceutil/trace.go:171","msg":"trace[1470763396] transaction","detail":"{read_only:false; response_revision:606; number_of_response:1; }","duration":"198.361458ms","start":"2024-12-13T01:35:03.421275Z","end":"2024-12-13T01:35:03.619636Z","steps":["trace[1470763396] 'process raft request' (duration: 198.272291ms)"],"step_count":1} Dec 13 01:35:03.620025 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.619813Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"195.977485ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/calico-cni-plugin\" ","response":"range_response_count:1 size:537"} Dec 13 01:35:03.620598 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.619852Z","caller":"traceutil/trace.go:171","msg":"trace[1116007171] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/calico-cni-plugin; range_end:; response_count:1; response_revision:606; }","duration":"196.062644ms","start":"2024-12-13T01:35:03.423780Z","end":"2024-12-13T01:35:03.619842Z","steps":["trace[1116007171] 'agreement among raft nodes before linearized reading' (duration: 195.931858ms)"],"step_count":1} Dec 13 01:35:03.661946 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661150Z","caller":"traceutil/trace.go:171","msg":"trace[365356018] transaction","detail":"{read_only:false; response_revision:610; number_of_response:1; }","duration":"219.840853ms","start":"2024-12-13T01:35:03.441275Z","end":"2024-12-13T01:35:03.661116Z","steps":["trace[365356018] 'process raft request' (duration: 219.776602ms)"],"step_count":1} Dec 13 01:35:03.661946 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661208Z","caller":"traceutil/trace.go:171","msg":"trace[1883696945] transaction","detail":"{read_only:false; response_revision:607; number_of_response:1; }","duration":"222.183578ms","start":"2024-12-13T01:35:03.439015Z","end":"2024-12-13T01:35:03.661199Z","steps":["trace[1883696945] 'process raft request' (duration: 221.91798ms)"],"step_count":1} Dec 13 01:35:03.661946 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661258Z","caller":"traceutil/trace.go:171","msg":"trace[543451605] transaction","detail":"{read_only:false; response_revision:609; number_of_response:1; }","duration":"221.372846ms","start":"2024-12-13T01:35:03.439877Z","end":"2024-12-13T01:35:03.661250Z","steps":["trace[543451605] 'process raft request' (duration: 221.150449ms)"],"step_count":1} Dec 13 01:35:03.661946 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661282Z","caller":"traceutil/trace.go:171","msg":"trace[299804548] transaction","detail":"{read_only:false; response_revision:608; number_of_response:1; }","duration":"221.450362ms","start":"2024-12-13T01:35:03.439824Z","end":"2024-12-13T01:35:03.661274Z","steps":["trace[299804548] 'process raft request' (duration: 221.179585ms)"],"step_count":1} Dec 13 01:35:03.661946 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661168Z","caller":"traceutil/trace.go:171","msg":"trace[1228988033] transaction","detail":"{read_only:false; response_revision:611; number_of_response:1; }","duration":"212.567995ms","start":"2024-12-13T01:35:03.448583Z","end":"2024-12-13T01:35:03.661151Z","steps":["trace[1228988033] 'process raft request' (duration: 212.489447ms)"],"step_count":1} Dec 13 01:35:03.662190 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.661426Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"112.559383ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/configmaps/calico-system/cni-config\" ","response":"range_response_count:1 size:1234"} Dec 13 01:35:03.662190 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661461Z","caller":"traceutil/trace.go:171","msg":"trace[1112356502] range","detail":"{range_begin:/registry/configmaps/calico-system/cni-config; range_end:; response_count:1; response_revision:612; }","duration":"112.613225ms","start":"2024-12-13T01:35:03.548839Z","end":"2024-12-13T01:35:03.661452Z","steps":["trace[1112356502] 'agreement among raft nodes before linearized reading' (duration: 112.511293ms)"],"step_count":1} Dec 13 01:35:03.662190 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.661495Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"162.683599ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-cni-plugin\" ","response":"range_response_count:1 size:716"} Dec 13 01:35:03.662190 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661536Z","caller":"traceutil/trace.go:171","msg":"trace[637961656] range","detail":"{range_begin:/registry/clusterrolebindings/calico-cni-plugin; range_end:; response_count:1; response_revision:612; }","duration":"162.739865ms","start":"2024-12-13T01:35:03.498770Z","end":"2024-12-13T01:35:03.661510Z","steps":["trace[637961656] 'agreement among raft nodes before linearized reading' (duration: 162.625519ms)"],"step_count":1} Dec 13 01:35:03.662190 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.661611Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"138.130366ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/installations/default\" ","response":"range_response_count:1 size:3434"} Dec 13 01:35:03.662312 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661634Z","caller":"traceutil/trace.go:171","msg":"trace[1994991261] range","detail":"{range_begin:/registry/operator.tigera.io/installations/default; range_end:; response_count:1; response_revision:612; }","duration":"138.168959ms","start":"2024-12-13T01:35:03.523459Z","end":"2024-12-13T01:35:03.661628Z","steps":["trace[1994991261] 'agreement among raft nodes before linearized reading' (duration: 138.10541ms)"],"step_count":1} Dec 13 01:35:03.662312 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661649Z","caller":"traceutil/trace.go:171","msg":"trace[1267016248] transaction","detail":"{read_only:false; response_revision:612; number_of_response:1; }","duration":"154.954595ms","start":"2024-12-13T01:35:03.506687Z","end":"2024-12-13T01:35:03.661641Z","steps":["trace[1267016248] 'process raft request' (duration: 154.400075ms)"],"step_count":1} Dec 13 01:35:03.662312 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.661798Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"188.334582ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/calico-cni-plugin\" ","response":"range_response_count:1 size:789"} Dec 13 01:35:03.662312 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661833Z","caller":"traceutil/trace.go:171","msg":"trace[960466707] range","detail":"{range_begin:/registry/clusterroles/calico-cni-plugin; range_end:; response_count:1; response_revision:612; }","duration":"188.569744ms","start":"2024-12-13T01:35:03.473253Z","end":"2024-12-13T01:35:03.661823Z","steps":["trace[960466707] 'agreement among raft nodes before linearized reading' (duration: 188.314745ms)"],"step_count":1} Dec 13 01:35:03.662312 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:03.661847Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"213.109881ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/operator.tigera.io/apiservers/default\" ","response":"range_response_count:1 size:766"} Dec 13 01:35:03.662441 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:03.661870Z","caller":"traceutil/trace.go:171","msg":"trace[299915320] range","detail":"{range_begin:/registry/operator.tigera.io/apiservers/default; range_end:; response_count:1; response_revision:612; }","duration":"213.152732ms","start":"2024-12-13T01:35:03.448711Z","end":"2024-12-13T01:35:03.661864Z","steps":["trace[299915320] 'agreement among raft nodes before linearized reading' (duration: 213.09809ms)"],"step_count":1} Dec 13 01:35:13.909826 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:13.909394Z","caller":"traceutil/trace.go:171","msg":"trace[726184448] transaction","detail":"{read_only:false; response_revision:715; number_of_response:1; }","duration":"132.954086ms","start":"2024-12-13T01:35:13.776414Z","end":"2024-12-13T01:35:13.909368Z","steps":["trace[726184448] 'process raft request' (duration: 132.755334ms)"],"step_count":1} Dec 13 01:35:19.085924 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:19.085482Z","caller":"traceutil/trace.go:171","msg":"trace[876922883] transaction","detail":"{read_only:false; response_revision:741; number_of_response:1; }","duration":"144.39451ms","start":"2024-12-13T01:35:18.941070Z","end":"2024-12-13T01:35:19.085465Z","steps":["trace[876922883] 'process raft request' (duration: 144.318966ms)"],"step_count":1} Dec 13 01:35:19.085924 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:19.085483Z","caller":"traceutil/trace.go:171","msg":"trace[1149034630] transaction","detail":"{read_only:false; response_revision:740; number_of_response:1; }","duration":"146.722527ms","start":"2024-12-13T01:35:18.938742Z","end":"2024-12-13T01:35:19.085465Z","steps":["trace[1149034630] 'process raft request' (duration: 104.569063ms)","trace[1149034630] 'compare' (duration: 41.957117ms)"],"step_count":2} Dec 13 01:35:19.681288 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:19.680705Z","caller":"traceutil/trace.go:171","msg":"trace[203313460] transaction","detail":"{read_only:false; response_revision:748; number_of_response:1; }","duration":"389.018539ms","start":"2024-12-13T01:35:19.291662Z","end":"2024-12-13T01:35:19.680680Z","steps":["trace[203313460] 'process raft request' (duration: 303.519076ms)","trace[203313460] 'compare' (duration: 85.329937ms)"],"step_count":2} Dec 13 01:35:19.681288 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:19.680935Z","caller":"traceutil/trace.go:171","msg":"trace[771405001] transaction","detail":"{read_only:false; response_revision:750; number_of_response:1; }","duration":"280.415674ms","start":"2024-12-13T01:35:19.400509Z","end":"2024-12-13T01:35:19.680925Z","steps":["trace[771405001] 'process raft request' (duration: 280.315291ms)"],"step_count":1} Dec 13 01:35:19.681288 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:19.680951Z","caller":"traceutil/trace.go:171","msg":"trace[1431241166] transaction","detail":"{read_only:false; response_revision:749; number_of_response:1; }","duration":"363.123852ms","start":"2024-12-13T01:35:19.317809Z","end":"2024-12-13T01:35:19.680933Z","steps":["trace[1431241166] 'process raft request' (duration: 362.84171ms)"],"step_count":1} Dec 13 01:35:19.681672 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:19.681094Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-12-13T01:35:19.317786Z","time spent":"363.236149ms","remote":"10.0.0.100:53720","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Dec 13 01:35:19.681672 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:19.680887Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-12-13T01:35:19.291639Z","time spent":"389.144601ms","remote":"10.0.0.100:53630","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":5403,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Dec 13 01:35:20.230392 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:20.229976Z","caller":"traceutil/trace.go:171","msg":"trace[1723264347] transaction","detail":"{read_only:false; response_revision:753; number_of_response:1; }","duration":"140.817482ms","start":"2024-12-13T01:35:20.089139Z","end":"2024-12-13T01:35:20.229956Z","steps":["trace[1723264347] 'process raft request' (duration: 123.140259ms)","trace[1723264347] 'compare' (duration: 17.564888ms)"],"step_count":2} Dec 13 01:35:21.975415 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:21.975044Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"143.037718ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-node-lease/10.0.0.109\" ","response":"range_response_count:0 size:5"} Dec 13 01:35:21.975415 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:21.975104Z","caller":"traceutil/trace.go:171","msg":"trace[414287747] range","detail":"{range_begin:/registry/leases/kube-node-lease/10.0.0.109; range_end:; response_count:0; response_revision:774; }","duration":"143.133813ms","start":"2024-12-13T01:35:21.831958Z","end":"2024-12-13T01:35:21.975092Z","steps":["trace[414287747] 'range keys from in-memory index tree' (duration: 142.976841ms)"],"step_count":1} Dec 13 01:35:21.985123 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:21.984834Z","caller":"traceutil/trace.go:171","msg":"trace[2025628205] transaction","detail":"{read_only:false; response_revision:775; number_of_response:1; }","duration":"152.540053ms","start":"2024-12-13T01:35:21.832269Z","end":"2024-12-13T01:35:21.984810Z","steps":["trace[2025628205] 'process raft request' (duration: 152.432727ms)"],"step_count":1} Dec 13 01:35:22.227167 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:22.226742Z","caller":"traceutil/trace.go:171","msg":"trace[1123565765] transaction","detail":"{read_only:false; response_revision:776; number_of_response:1; }","duration":"183.814223ms","start":"2024-12-13T01:35:22.042909Z","end":"2024-12-13T01:35:22.226723Z","steps":["trace[1123565765] 'process raft request' (duration: 122.325221ms)","trace[1123565765] 'compare' (duration: 61.370565ms)"],"step_count":2} Dec 13 01:35:22.390623 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:22.390302Z","caller":"traceutil/trace.go:171","msg":"trace[899320390] transaction","detail":"{read_only:false; response_revision:780; number_of_response:1; }","duration":"103.971629ms","start":"2024-12-13T01:35:22.286314Z","end":"2024-12-13T01:35:22.390285Z","steps":["trace[899320390] 'process raft request' (duration: 87.358768ms)","trace[899320390] 'compare' (duration: 16.535383ms)"],"step_count":2} Dec 13 01:35:26.410190 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:26.409760Z","caller":"traceutil/trace.go:171","msg":"trace[1073931577] linearizableReadLoop","detail":"{readStateIndex:854; appliedIndex:853; }","duration":"128.067044ms","start":"2024-12-13T01:35:26.281663Z","end":"2024-12-13T01:35:26.409730Z","steps":["trace[1073931577] 'read index received' (duration: 83.918225ms)","trace[1073931577] 'applied index is now lower than readState.Index' (duration: 44.147987ms)"],"step_count":2} Dec 13 01:35:26.410925 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:26.409876Z","caller":"traceutil/trace.go:171","msg":"trace[1863317393] transaction","detail":"{read_only:false; response_revision:834; number_of_response:1; }","duration":"155.164009ms","start":"2024-12-13T01:35:26.254694Z","end":"2024-12-13T01:35:26.409858Z","steps":["trace[1863317393] 'process raft request' (duration: 110.801441ms)","trace[1863317393] 'compare' (duration: 44.119413ms)"],"step_count":2} Dec 13 01:35:26.410925 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:26.409952Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"128.273289ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/calico-system/csi-node-driver-fgsq6.181098ac6a690823\" ","response":"range_response_count:1 size:870"} Dec 13 01:35:26.410925 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:26.409983Z","caller":"traceutil/trace.go:171","msg":"trace[530292186] range","detail":"{range_begin:/registry/events/calico-system/csi-node-driver-fgsq6.181098ac6a690823; range_end:; response_count:1; response_revision:834; }","duration":"128.342272ms","start":"2024-12-13T01:35:26.281629Z","end":"2024-12-13T01:35:26.409972Z","steps":["trace[530292186] 'agreement among raft nodes before linearized reading' (duration: 128.229676ms)"],"step_count":1} Dec 13 01:35:26.410925 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:26.410005Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"113.640317ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/calico-system/calico-node-ndjbz\" ","response":"range_response_count:1 size:14113"} Dec 13 01:35:26.411082 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:26.410027Z","caller":"traceutil/trace.go:171","msg":"trace[1059474764] range","detail":"{range_begin:/registry/pods/calico-system/calico-node-ndjbz; range_end:; response_count:1; response_revision:834; }","duration":"113.67933ms","start":"2024-12-13T01:35:26.296340Z","end":"2024-12-13T01:35:26.410020Z","steps":["trace[1059474764] 'agreement among raft nodes before linearized reading' (duration: 113.612232ms)"],"step_count":1} Dec 13 01:35:29.031242 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:29.030844Z","caller":"traceutil/trace.go:171","msg":"trace[1106397581] transaction","detail":"{read_only:false; response_revision:846; number_of_response:1; }","duration":"131.013175ms","start":"2024-12-13T01:35:28.899810Z","end":"2024-12-13T01:35:29.030823Z","steps":["trace[1106397581] 'process raft request' (duration: 130.902654ms)"],"step_count":1} Dec 13 01:35:35.087254 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:35.086865Z","caller":"traceutil/trace.go:171","msg":"trace[589980658] linearizableReadLoop","detail":"{readStateIndex:938; appliedIndex:937; }","duration":"195.313132ms","start":"2024-12-13T01:35:34.891533Z","end":"2024-12-13T01:35:35.086846Z","steps":["trace[589980658] 'read index received' (duration: 137.279197ms)","trace[589980658] 'applied index is now lower than readState.Index' (duration: 58.033444ms)"],"step_count":2} Dec 13 01:35:35.087254 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:35.086910Z","caller":"traceutil/trace.go:171","msg":"trace[340542632] transaction","detail":"{read_only:false; response_revision:915; number_of_response:1; }","duration":"208.102318ms","start":"2024-12-13T01:35:34.878791Z","end":"2024-12-13T01:35:35.086893Z","steps":["trace[340542632] 'process raft request' (duration: 150.004031ms)","trace[340542632] 'compare' (duration: 57.971585ms)"],"step_count":2} Dec 13 01:35:35.087254 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:35.087025Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"195.4961ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/secrets/tigera-operator/calico-apiserver-certs\" ","response":"range_response_count:1 size:4747"} Dec 13 01:35:35.087254 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:35.087048Z","caller":"traceutil/trace.go:171","msg":"trace[696999537] range","detail":"{range_begin:/registry/secrets/tigera-operator/calico-apiserver-certs; range_end:; response_count:1; response_revision:915; }","duration":"195.562088ms","start":"2024-12-13T01:35:34.891479Z","end":"2024-12-13T01:35:35.087041Z","steps":["trace[696999537] 'agreement among raft nodes before linearized reading' (duration: 195.465033ms)"],"step_count":1} Dec 13 01:35:36.701103 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:36.700651Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"154.147182ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Dec 13 01:35:36.701103 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:36.700747Z","caller":"traceutil/trace.go:171","msg":"trace[449621893] linearizableReadLoop","detail":"{readStateIndex:978; appliedIndex:977; }","duration":"169.095895ms","start":"2024-12-13T01:35:36.531635Z","end":"2024-12-13T01:35:36.700731Z","steps":["trace[449621893] 'read index received' (duration: 14.722351ms)","trace[449621893] 'applied index is now lower than readState.Index' (duration: 154.372672ms)"],"step_count":2} Dec 13 01:35:36.701103 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:36.700782Z","caller":"traceutil/trace.go:171","msg":"trace[358971575] transaction","detail":"{read_only:false; response_revision:954; number_of_response:1; }","duration":"171.433318ms","start":"2024-12-13T01:35:36.529324Z","end":"2024-12-13T01:35:36.700757Z","steps":["trace[358971575] 'process raft request' (duration: 17.090061ms)","trace[358971575] 'compare' (duration: 153.962201ms)"],"step_count":2} Dec 13 01:35:36.701103 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:36.700917Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"169.275527ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/calico-apiserver\" ","response":"range_response_count:1 size:773"} Dec 13 01:35:36.701728 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:36.700949Z","caller":"traceutil/trace.go:171","msg":"trace[1342712291] range","detail":"{range_begin:/registry/namespaces/calico-apiserver; range_end:; response_count:1; response_revision:954; }","duration":"169.31944ms","start":"2024-12-13T01:35:36.531621Z","end":"2024-12-13T01:35:36.700940Z","steps":["trace[1342712291] 'agreement among raft nodes before linearized reading' (duration: 169.175496ms)"],"step_count":1} Dec 13 01:35:37.498262 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:37.497853Z","caller":"traceutil/trace.go:171","msg":"trace[2032966088] linearizableReadLoop","detail":"{readStateIndex:987; appliedIndex:986; }","duration":"117.603073ms","start":"2024-12-13T01:35:37.380231Z","end":"2024-12-13T01:35:37.497834Z","steps":["trace[2032966088] 'read index received' (duration: 31.990488ms)","trace[2032966088] 'applied index is now lower than readState.Index' (duration: 85.611904ms)"],"step_count":2} Dec 13 01:35:37.498262 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:37.497955Z","caller":"traceutil/trace.go:171","msg":"trace[1088881579] transaction","detail":"{read_only:false; response_revision:963; number_of_response:1; }","duration":"118.895996ms","start":"2024-12-13T01:35:37.379050Z","end":"2024-12-13T01:35:37.497946Z","steps":["trace[1088881579] 'process raft request' (duration: 33.138735ms)","trace[1088881579] 'compare' (duration: 85.559525ms)"],"step_count":2} Dec 13 01:35:37.498262 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:37.498076Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.829965ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/calico-apiserver/calico-apiserver-89794f578-hrxnn\" ","response":"range_response_count:1 size:5418"} Dec 13 01:35:37.498262 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:37.498108Z","caller":"traceutil/trace.go:171","msg":"trace[1475333219] range","detail":"{range_begin:/registry/pods/calico-apiserver/calico-apiserver-89794f578-hrxnn; range_end:; response_count:1; response_revision:963; }","duration":"117.883337ms","start":"2024-12-13T01:35:37.380216Z","end":"2024-12-13T01:35:37.498100Z","steps":["trace[1475333219] 'agreement among raft nodes before linearized reading' (duration: 117.801872ms)"],"step_count":1} Dec 13 01:35:38.132838 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:38.131980Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"186.179043ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} Dec 13 01:35:38.132838 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:38.132155Z","caller":"traceutil/trace.go:171","msg":"trace[1337311859] transaction","detail":"{read_only:false; response_revision:970; number_of_response:1; }","duration":"230.158624ms","start":"2024-12-13T01:35:37.901984Z","end":"2024-12-13T01:35:38.132143Z","steps":["trace[1337311859] 'process raft request' (duration: 230.104801ms)"],"step_count":1} Dec 13 01:35:38.132838 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:38.132301Z","caller":"traceutil/trace.go:171","msg":"trace[1612721140] transaction","detail":"{read_only:false; response_revision:969; number_of_response:1; }","duration":"273.478259ms","start":"2024-12-13T01:35:37.858792Z","end":"2024-12-13T01:35:38.132270Z","steps":["trace[1612721140] 'process raft request' (duration: 86.962015ms)","trace[1612721140] 'compare' (duration: 186.057942ms)"],"step_count":2} Dec 13 01:35:40.595293 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:40.594930Z","caller":"traceutil/trace.go:171","msg":"trace[421684483] transaction","detail":"{read_only:false; response_revision:1000; number_of_response:1; }","duration":"189.405591ms","start":"2024-12-13T01:35:40.405493Z","end":"2024-12-13T01:35:40.594898Z","steps":["trace[421684483] 'process raft request' (duration: 94.199214ms)","trace[421684483] 'compare' (duration: 95.082531ms)"],"step_count":2} Dec 13 01:35:40.903751 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:40.903328Z","caller":"traceutil/trace.go:171","msg":"trace[534875931] transaction","detail":"{read_only:false; response_revision:1001; number_of_response:1; }","duration":"113.393871ms","start":"2024-12-13T01:35:40.789915Z","end":"2024-12-13T01:35:40.903309Z","steps":["trace[534875931] 'process raft request' (duration: 113.305965ms)"],"step_count":1} Dec 13 01:35:41.981683 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:41.981316Z","caller":"traceutil/trace.go:171","msg":"trace[761364083] transaction","detail":"{read_only:false; response_revision:1005; number_of_response:1; }","duration":"100.578156ms","start":"2024-12-13T01:35:41.880708Z","end":"2024-12-13T01:35:41.981286Z","steps":["trace[761364083] 'process raft request' (duration: 100.464079ms)"],"step_count":1} Dec 13 01:35:47.408185 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:47.407726Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"183.753157ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:5"} Dec 13 01:35:47.408185 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:47.407810Z","caller":"traceutil/trace.go:171","msg":"trace[1811908158] linearizableReadLoop","detail":"{readStateIndex:1093; appliedIndex:1092; }","duration":"106.052784ms","start":"2024-12-13T01:35:47.301745Z","end":"2024-12-13T01:35:47.407798Z","steps":["trace[1811908158] 'read index received' (duration: 42.561µs)","trace[1811908158] 'applied index is now lower than readState.Index' (duration: 106.009462ms)"],"step_count":2} Dec 13 01:35:47.408185 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:47.407866Z","caller":"traceutil/trace.go:171","msg":"trace[1371791176] transaction","detail":"{read_only:false; number_of_response:0; response_revision:1047; }","duration":"226.027188ms","start":"2024-12-13T01:35:47.181808Z","end":"2024-12-13T01:35:47.407835Z","steps":["trace[1371791176] 'process raft request' (duration: 42.112565ms)","trace[1371791176] 'compare' (duration: 183.706478ms)"],"step_count":2} Dec 13 01:35:47.408817 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:47.407987Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"106.215152ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/tigera-operator/operator-lock\" ","response":"range_response_count:1 size:480"} Dec 13 01:35:47.408817 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:47.408059Z","caller":"traceutil/trace.go:171","msg":"trace[924956297] range","detail":"{range_begin:/registry/leases/tigera-operator/operator-lock; range_end:; response_count:1; response_revision:1047; }","duration":"106.330441ms","start":"2024-12-13T01:35:47.301713Z","end":"2024-12-13T01:35:47.408043Z","steps":["trace[924956297] 'agreement among raft nodes before linearized reading' (duration: 106.120923ms)"],"step_count":1} Dec 13 01:35:48.802427 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:48.801937Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"180.043765ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:5"} Dec 13 01:35:48.802427 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.802033Z","caller":"traceutil/trace.go:171","msg":"trace[335888342] transaction","detail":"{read_only:false; number_of_response:0; response_revision:1054; }","duration":"222.61572ms","start":"2024-12-13T01:35:48.579401Z","end":"2024-12-13T01:35:48.802016Z","steps":["trace[335888342] 'process raft request' (duration: 42.445476ms)","trace[335888342] 'compare' (duration: 179.996454ms)"],"step_count":2} Dec 13 01:35:48.831556 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.830932Z","caller":"traceutil/trace.go:171","msg":"trace[391449244] linearizableReadLoop","detail":"{readStateIndex:1131; appliedIndex:1129; }","duration":"222.212355ms","start":"2024-12-13T01:35:48.608700Z","end":"2024-12-13T01:35:48.830912Z","steps":["trace[391449244] 'read index received' (duration: 13.354618ms)","trace[391449244] 'applied index is now lower than readState.Index' (duration: 208.857126ms)"],"step_count":2} Dec 13 01:35:48.831770 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.831005Z","caller":"traceutil/trace.go:171","msg":"trace[1036500727] transaction","detail":"{read_only:false; response_revision:1055; number_of_response:1; }","duration":"244.535757ms","start":"2024-12-13T01:35:48.586444Z","end":"2024-12-13T01:35:48.830980Z","steps":["trace[1036500727] 'process raft request' (duration: 244.35804ms)"],"step_count":1} Dec 13 01:35:48.831770 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:48.831113Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"222.39438ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/10.0.0.109\" ","response":"range_response_count:1 size:3086"} Dec 13 01:35:48.831770 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.831134Z","caller":"traceutil/trace.go:171","msg":"trace[1683421816] range","detail":"{range_begin:/registry/minions/10.0.0.109; range_end:; response_count:1; response_revision:1055; }","duration":"222.434818ms","start":"2024-12-13T01:35:48.608693Z","end":"2024-12-13T01:35:48.831128Z","steps":["trace[1683421816] 'agreement among raft nodes before linearized reading' (duration: 222.328225ms)"],"step_count":1} Dec 13 01:35:48.831770 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:48.831146Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"155.546376ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Dec 13 01:35:48.831770 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.831169Z","caller":"traceutil/trace.go:171","msg":"trace[534057838] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1055; }","duration":"155.60698ms","start":"2024-12-13T01:35:48.675553Z","end":"2024-12-13T01:35:48.831160Z","steps":["trace[534057838] 'agreement among raft nodes before linearized reading' (duration: 155.554791ms)"],"step_count":1} Dec 13 01:35:48.831928 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:48.831282Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"131.464825ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/calico-system/calico-cni-plugin\" ","response":"range_response_count:1 size:537"} Dec 13 01:35:48.831928 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:48.831289Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"125.708508ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/clusterinformations/default\" ","response":"range_response_count:1 size:886"} Dec 13 01:35:48.831928 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.831300Z","caller":"traceutil/trace.go:171","msg":"trace[1326818876] range","detail":"{range_begin:/registry/serviceaccounts/calico-system/calico-cni-plugin; range_end:; response_count:1; response_revision:1055; }","duration":"131.511023ms","start":"2024-12-13T01:35:48.699783Z","end":"2024-12-13T01:35:48.831294Z","steps":["trace[1326818876] 'agreement among raft nodes before linearized reading' (duration: 131.426393ms)"],"step_count":1} Dec 13 01:35:48.831928 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:48.831317Z","caller":"traceutil/trace.go:171","msg":"trace[1837322696] range","detail":"{range_begin:/registry/crd.projectcalico.org/clusterinformations/default; range_end:; response_count:1; response_revision:1055; }","duration":"125.797748ms","start":"2024-12-13T01:35:48.705510Z","end":"2024-12-13T01:35:48.831308Z","steps":["trace[1837322696] 'agreement among raft nodes before linearized reading' (duration: 125.687328ms)"],"step_count":1} Dec 13 01:35:52.181142 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:52.180608Z","caller":"traceutil/trace.go:171","msg":"trace[554319430] transaction","detail":"{read_only:false; response_revision:1071; number_of_response:1; }","duration":"122.166503ms","start":"2024-12-13T01:35:52.058421Z","end":"2024-12-13T01:35:52.180587Z","steps":["trace[554319430] 'process raft request' (duration: 121.998706ms)"],"step_count":1} Dec 13 01:35:53.361557 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.361060Z","caller":"traceutil/trace.go:171","msg":"trace[998129639] linearizableReadLoop","detail":"{readStateIndex:1195; appliedIndex:1193; }","duration":"126.389036ms","start":"2024-12-13T01:35:53.234655Z","end":"2024-12-13T01:35:53.361045Z","steps":["trace[998129639] 'read index received' (duration: 42.168255ms)","trace[998129639] 'applied index is now lower than readState.Index' (duration: 84.2202ms)"],"step_count":2} Dec 13 01:35:53.361557 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.361113Z","caller":"traceutil/trace.go:171","msg":"trace[937070145] transaction","detail":"{read_only:false; response_revision:1082; number_of_response:1; }","duration":"158.298623ms","start":"2024-12-13T01:35:53.202781Z","end":"2024-12-13T01:35:53.361080Z","steps":["trace[937070145] 'process raft request' (duration: 70.287714ms)","trace[937070145] 'compare' (duration: 87.833332ms)"],"step_count":2} Dec 13 01:35:53.361557 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:53.361181Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"126.526607ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/crd.projectcalico.org/ipamhandles/k8s-pod-network.08fb52641e66273b17fd53b04aabbbfea359af2ad53b93558ad36a652cda48b7\" ","response":"range_response_count:0 size:5"} Dec 13 01:35:53.361557 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.361210Z","caller":"traceutil/trace.go:171","msg":"trace[1636954841] range","detail":"{range_begin:/registry/crd.projectcalico.org/ipamhandles/k8s-pod-network.08fb52641e66273b17fd53b04aabbbfea359af2ad53b93558ad36a652cda48b7; range_end:; response_count:0; response_revision:1083; }","duration":"126.602371ms","start":"2024-12-13T01:35:53.234601Z","end":"2024-12-13T01:35:53.361203Z","steps":["trace[1636954841] 'agreement among raft nodes before linearized reading' (duration: 126.508012ms)"],"step_count":1} Dec 13 01:35:53.362466 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.361276Z","caller":"traceutil/trace.go:171","msg":"trace[2114119341] transaction","detail":"{read_only:false; response_revision:1083; number_of_response:1; }","duration":"157.543792ms","start":"2024-12-13T01:35:53.203727Z","end":"2024-12-13T01:35:53.361271Z","steps":["trace[2114119341] 'process raft request' (duration: 157.277176ms)"],"step_count":1} Dec 13 01:35:53.448739 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.448341Z","caller":"traceutil/trace.go:171","msg":"trace[1087517356] transaction","detail":"{read_only:false; response_revision:1084; number_of_response:1; }","duration":"205.347317ms","start":"2024-12-13T01:35:53.242946Z","end":"2024-12-13T01:35:53.448294Z","steps":["trace[1087517356] 'process raft request' (duration: 205.215398ms)"],"step_count":1} Dec 13 01:35:53.516790 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.516262Z","caller":"traceutil/trace.go:171","msg":"trace[1387211799] transaction","detail":"{read_only:false; response_revision:1085; number_of_response:1; }","duration":"149.484089ms","start":"2024-12-13T01:35:53.366759Z","end":"2024-12-13T01:35:53.516243Z","steps":["trace[1387211799] 'process raft request' (duration: 141.568793ms)"],"step_count":1} Dec 13 01:35:53.516790 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:53.516587Z","caller":"traceutil/trace.go:171","msg":"trace[1764648948] transaction","detail":"{read_only:false; response_revision:1086; number_of_response:1; }","duration":"108.223735ms","start":"2024-12-13T01:35:53.408340Z","end":"2024-12-13T01:35:53.516564Z","steps":["trace[1764648948] 'process raft request' (duration: 107.857682ms)"],"step_count":1} Dec 13 01:35:56.786967 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:56.786545Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"126.241803ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Dec 13 01:35:56.786967 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:56.786634Z","caller":"traceutil/trace.go:171","msg":"trace[1703386891] linearizableReadLoop","detail":"{readStateIndex:1229; appliedIndex:1228; }","duration":"114.673235ms","start":"2024-12-13T01:35:56.671949Z","end":"2024-12-13T01:35:56.786622Z","steps":["trace[1703386891] 'read index received' (duration: 37.541µs)","trace[1703386891] 'applied index is now lower than readState.Index' (duration: 114.634993ms)"],"step_count":2} Dec 13 01:35:56.786967 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:35:56.786671Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"114.724873ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Dec 13 01:35:56.786967 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:56.786692Z","caller":"traceutil/trace.go:171","msg":"trace[1578537545] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1116; }","duration":"114.770821ms","start":"2024-12-13T01:35:56.671916Z","end":"2024-12-13T01:35:56.786686Z","steps":["trace[1578537545] 'agreement among raft nodes before linearized reading' (duration: 114.735784ms)"],"step_count":1} Dec 13 01:35:56.787746 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:35:56.786683Z","caller":"traceutil/trace.go:171","msg":"trace[1332761725] transaction","detail":"{read_only:false; response_revision:1116; number_of_response:1; }","duration":"189.079738ms","start":"2024-12-13T01:35:56.597578Z","end":"2024-12-13T01:35:56.786658Z","steps":["trace[1332761725] 'process raft request' (duration: 62.630571ms)","trace[1332761725] 'compare' (duration: 126.145001ms)"],"step_count":2} Dec 13 01:36:06.205320 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:06.204913Z","caller":"traceutil/trace.go:171","msg":"trace[1861646595] linearizableReadLoop","detail":"{readStateIndex:1275; appliedIndex:1274; }","duration":"139.981111ms","start":"2024-12-13T01:36:06.064908Z","end":"2024-12-13T01:36:06.204889Z","steps":["trace[1861646595] 'read index received' (duration: 69.53615ms)","trace[1861646595] 'applied index is now lower than readState.Index' (duration: 70.444039ms)"],"step_count":2} Dec 13 01:36:06.205320 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:06.205087Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"140.16103ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/deployments/calico-system/calico-kube-controllers\" ","response":"range_response_count:1 size:5275"} Dec 13 01:36:06.205320 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:06.205119Z","caller":"traceutil/trace.go:171","msg":"trace[1218874237] range","detail":"{range_begin:/registry/deployments/calico-system/calico-kube-controllers; range_end:; response_count:1; response_revision:1158; }","duration":"140.213559ms","start":"2024-12-13T01:36:06.064896Z","end":"2024-12-13T01:36:06.205110Z","steps":["trace[1218874237] 'agreement among raft nodes before linearized reading' (duration: 140.093011ms)"],"step_count":1} Dec 13 01:36:06.205904 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:06.205165Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.9642ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-apiserver-access-calico-crds\" ","response":"range_response_count:1 size:661"} Dec 13 01:36:06.205904 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:06.205237Z","caller":"traceutil/trace.go:171","msg":"trace[584500141] range","detail":"{range_begin:/registry/clusterrolebindings/calico-apiserver-access-calico-crds; range_end:; response_count:1; response_revision:1158; }","duration":"120.082304ms","start":"2024-12-13T01:36:06.085135Z","end":"2024-12-13T01:36:06.205217Z","steps":["trace[584500141] 'agreement among raft nodes before linearized reading' (duration: 119.878258ms)"],"step_count":1} Dec 13 01:36:07.861181 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:07.860861Z","caller":"traceutil/trace.go:171","msg":"trace[1580378280] linearizableReadLoop","detail":"{readStateIndex:1279; appliedIndex:1278; }","duration":"186.292141ms","start":"2024-12-13T01:36:07.674548Z","end":"2024-12-13T01:36:07.860841Z","steps":["trace[1580378280] 'read index received' (duration: 124.121658ms)","trace[1580378280] 'applied index is now lower than readState.Index' (duration: 62.169832ms)"],"step_count":2} Dec 13 01:36:07.861181 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:07.860897Z","caller":"traceutil/trace.go:171","msg":"trace[1640314592] transaction","detail":"{read_only:false; response_revision:1162; number_of_response:1; }","duration":"208.59559ms","start":"2024-12-13T01:36:07.652282Z","end":"2024-12-13T01:36:07.860878Z","steps":["trace[1640314592] 'process raft request' (duration: 146.440317ms)","trace[1640314592] 'compare' (duration: 62.02141ms)"],"step_count":2} Dec 13 01:36:07.861727 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:07.860965Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"186.411999ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Dec 13 01:36:07.861727 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:07.860986Z","caller":"traceutil/trace.go:171","msg":"trace[761499162] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1162; }","duration":"186.474828ms","start":"2024-12-13T01:36:07.674505Z","end":"2024-12-13T01:36:07.860980Z","steps":["trace[761499162] 'agreement among raft nodes before linearized reading' (duration: 186.434311ms)"],"step_count":1} Dec 13 01:36:07.861727 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:07.861033Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"175.877026ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-apiserver-delegate-auth\" ","response":"range_response_count:1 size:661"} Dec 13 01:36:07.861727 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:07.861034Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"114.776317ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-cni-plugin\" ","response":"range_response_count:1 size:716"} Dec 13 01:36:07.861727 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:07.861057Z","caller":"traceutil/trace.go:171","msg":"trace[437596986] range","detail":"{range_begin:/registry/clusterrolebindings/calico-cni-plugin; range_end:; response_count:1; response_revision:1162; }","duration":"114.829547ms","start":"2024-12-13T01:36:07.746221Z","end":"2024-12-13T01:36:07.861051Z","steps":["trace[437596986] 'agreement among raft nodes before linearized reading' (duration: 114.767279ms)"],"step_count":1} Dec 13 01:36:07.861876 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:07.861057Z","caller":"traceutil/trace.go:171","msg":"trace[708405118] range","detail":"{range_begin:/registry/clusterrolebindings/calico-apiserver-delegate-auth; range_end:; response_count:1; response_revision:1162; }","duration":"175.897885ms","start":"2024-12-13T01:36:07.685149Z","end":"2024-12-13T01:36:07.861047Z","steps":["trace[708405118] 'agreement among raft nodes before linearized reading' (duration: 175.814097ms)"],"step_count":1} Dec 13 01:36:08.067627 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.067086Z","caller":"traceutil/trace.go:171","msg":"trace[687330285] linearizableReadLoop","detail":"{readStateIndex:1280; appliedIndex:1279; }","duration":"200.228981ms","start":"2024-12-13T01:36:07.866835Z","end":"2024-12-13T01:36:08.067064Z","steps":["trace[687330285] 'read index received' (duration: 103.095727ms)","trace[687330285] 'applied index is now lower than readState.Index' (duration: 97.132723ms)"],"step_count":2} Dec 13 01:36:08.067627 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.067150Z","caller":"traceutil/trace.go:171","msg":"trace[647441382] transaction","detail":"{read_only:false; response_revision:1163; number_of_response:1; }","duration":"200.473914ms","start":"2024-12-13T01:36:07.866644Z","end":"2024-12-13T01:36:08.067118Z","steps":["trace[647441382] 'process raft request' (duration: 103.325681ms)","trace[647441382] 'compare' (duration: 96.998049ms)"],"step_count":2} Dec 13 01:36:08.067627 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:08.067260Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"195.960479ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/daemonsets/calico-system/calico-node\" ","response":"range_response_count:1 size:11240"} Dec 13 01:36:08.067627 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:08.067260Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"200.413309ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-extension-apiserver-auth-access\" ","response":"range_response_count:1 size:694"} Dec 13 01:36:08.067627 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.067286Z","caller":"traceutil/trace.go:171","msg":"trace[773554066] range","detail":"{range_begin:/registry/daemonsets/calico-system/calico-node; range_end:; response_count:1; response_revision:1163; }","duration":"195.998742ms","start":"2024-12-13T01:36:07.871280Z","end":"2024-12-13T01:36:08.067279Z","steps":["trace[773554066] 'agreement among raft nodes before linearized reading' (duration: 195.928499ms)"],"step_count":1} Dec 13 01:36:08.067933 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.067291Z","caller":"traceutil/trace.go:171","msg":"trace[633584887] range","detail":"{range_begin:/registry/clusterrolebindings/calico-extension-apiserver-auth-access; range_end:; response_count:1; response_revision:1163; }","duration":"200.464767ms","start":"2024-12-13T01:36:07.866821Z","end":"2024-12-13T01:36:08.067286Z","steps":["trace[633584887] 'agreement among raft nodes before linearized reading' (duration: 200.354007ms)"],"step_count":1} Dec 13 01:36:08.067933 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:08.067264Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"147.346373ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/tigera-operator/operator-lock\" ","response":"range_response_count:1 size:480"} Dec 13 01:36:08.067933 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.067328Z","caller":"traceutil/trace.go:171","msg":"trace[860676855] range","detail":"{range_begin:/registry/leases/tigera-operator/operator-lock; range_end:; response_count:1; response_revision:1163; }","duration":"147.421675ms","start":"2024-12-13T01:36:07.919902Z","end":"2024-12-13T01:36:08.067324Z","steps":["trace[860676855] 'agreement among raft nodes before linearized reading' (duration: 147.324702ms)"],"step_count":1} Dec 13 01:36:08.535012 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:08.534603Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"100.26061ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-typha:csr-creator\" ","response":"range_response_count:0 size:5"} Dec 13 01:36:08.535012 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:08.534685Z","caller":"traceutil/trace.go:171","msg":"trace[837873832] range","detail":"{range_begin:/registry/clusterrolebindings/calico-typha:csr-creator; range_end:; response_count:0; response_revision:1166; }","duration":"100.368823ms","start":"2024-12-13T01:36:08.434300Z","end":"2024-12-13T01:36:08.534669Z","steps":["trace[837873832] 'range keys from in-memory index tree' (duration: 100.225002ms)"],"step_count":1} Dec 13 01:36:09.009683 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:09.009100Z","caller":"traceutil/trace.go:171","msg":"trace[1506834810] linearizableReadLoop","detail":"{readStateIndex:1287; appliedIndex:1286; }","duration":"174.966445ms","start":"2024-12-13T01:36:08.834110Z","end":"2024-12-13T01:36:09.009077Z","steps":["trace[1506834810] 'read index received' (duration: 81.126378ms)","trace[1506834810] 'applied index is now lower than readState.Index' (duration: 93.839145ms)"],"step_count":2} Dec 13 01:36:09.009683 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:09.009215Z","caller":"traceutil/trace.go:171","msg":"trace[932294170] transaction","detail":"{read_only:false; response_revision:1170; number_of_response:1; }","duration":"177.399897ms","start":"2024-12-13T01:36:08.831804Z","end":"2024-12-13T01:36:09.009204Z","steps":["trace[932294170] 'process raft request' (duration: 83.451625ms)","trace[932294170] 'compare' (duration: 93.687048ms)"],"step_count":2} Dec 13 01:36:09.009683 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:09.009355Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"175.223151ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-cni-plugin\" ","response":"range_response_count:1 size:716"} Dec 13 01:36:09.009683 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:09.009379Z","caller":"traceutil/trace.go:171","msg":"trace[658407383] range","detail":"{range_begin:/registry/clusterrolebindings/calico-cni-plugin; range_end:; response_count:1; response_revision:1170; }","duration":"175.30166ms","start":"2024-12-13T01:36:08.834071Z","end":"2024-12-13T01:36:09.009372Z","steps":["trace[658407383] 'agreement among raft nodes before linearized reading' (duration: 175.211499ms)"],"step_count":1} Dec 13 01:36:09.009683 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:09.009355Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"124.739213ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-tiered-policy-passthrough\" ","response":"range_response_count:1 size:680"} Dec 13 01:36:09.010361 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:09.009424Z","caller":"traceutil/trace.go:171","msg":"trace[179046325] range","detail":"{range_begin:/registry/clusterrolebindings/calico-tiered-policy-passthrough; range_end:; response_count:1; response_revision:1170; }","duration":"124.830686ms","start":"2024-12-13T01:36:08.884587Z","end":"2024-12-13T01:36:09.009418Z","steps":["trace[179046325] 'agreement among raft nodes before linearized reading' (duration: 124.649072ms)"],"step_count":1} Dec 13 01:36:12.323541 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:12.323120Z","caller":"traceutil/trace.go:171","msg":"trace[2019300317] linearizableReadLoop","detail":"{readStateIndex:1324; appliedIndex:1323; }","duration":"138.701691ms","start":"2024-12-13T01:36:12.184400Z","end":"2024-12-13T01:36:12.323102Z","steps":["trace[2019300317] 'read index received' (duration: 138.615298ms)","trace[2019300317] 'applied index is now lower than readState.Index' (duration: 85.711µs)"],"step_count":2} Dec 13 01:36:12.323541 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:12.323170Z","caller":"traceutil/trace.go:171","msg":"trace[570259051] transaction","detail":"{read_only:false; response_revision:1206; number_of_response:1; }","duration":"171.993028ms","start":"2024-12-13T01:36:12.151150Z","end":"2024-12-13T01:36:12.323143Z","steps":["trace[570259051] 'process raft request' (duration: 171.848485ms)"],"step_count":1} Dec 13 01:36:12.323541 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:12.323235Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"138.822118ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/tigera-extension-apiserver-auth-access\" ","response":"range_response_count:0 size:5"} Dec 13 01:36:12.323541 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:12.323257Z","caller":"traceutil/trace.go:171","msg":"trace[1636008668] range","detail":"{range_begin:/registry/clusterrolebindings/tigera-extension-apiserver-auth-access; range_end:; response_count:0; response_revision:1206; }","duration":"138.885869ms","start":"2024-12-13T01:36:12.184363Z","end":"2024-12-13T01:36:12.323249Z","steps":["trace[1636008668] 'agreement among raft nodes before linearized reading' (duration: 138.838158ms)"],"step_count":1} Dec 13 01:36:13.057235 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:13.056873Z","caller":"traceutil/trace.go:171","msg":"trace[1667432341] transaction","detail":"{read_only:false; number_of_response:0; response_revision:1208; }","duration":"163.501326ms","start":"2024-12-13T01:36:12.893354Z","end":"2024-12-13T01:36:13.056855Z","steps":["trace[1667432341] 'process raft request' (duration: 163.38675ms)"],"step_count":1} Dec 13 01:36:13.057235 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:13.056948Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"121.859197ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/calico-node:csr-creator\" ","response":"range_response_count:0 size:5"} Dec 13 01:36:13.057235 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:13.056863Z","caller":"traceutil/trace.go:171","msg":"trace[1902699956] linearizableReadLoop","detail":"{readStateIndex:1327; appliedIndex:1326; }","duration":"121.766172ms","start":"2024-12-13T01:36:12.935075Z","end":"2024-12-13T01:36:13.056841Z","steps":["trace[1902699956] 'read index received' (duration: 121.652447ms)","trace[1902699956] 'applied index is now lower than readState.Index' (duration: 112.522µs)"],"step_count":2} Dec 13 01:36:13.057235 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:13.056980Z","caller":"traceutil/trace.go:171","msg":"trace[1975349862] range","detail":"{range_begin:/registry/clusterrolebindings/calico-node:csr-creator; range_end:; response_count:0; response_revision:1208; }","duration":"121.940181ms","start":"2024-12-13T01:36:12.935031Z","end":"2024-12-13T01:36:13.056971Z","steps":["trace[1975349862] 'agreement among raft nodes before linearized reading' (duration: 121.874567ms)"],"step_count":1} Dec 13 01:36:13.066680 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:13.066271Z","caller":"traceutil/trace.go:171","msg":"trace[1402235301] transaction","detail":"{read_only:false; response_revision:1209; number_of_response:1; }","duration":"105.007148ms","start":"2024-12-13T01:36:12.961231Z","end":"2024-12-13T01:36:13.066238Z","steps":["trace[1402235301] 'process raft request' (duration: 104.86534ms)"],"step_count":1} Dec 13 01:36:14.506951 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:14.506350Z","caller":"traceutil/trace.go:171","msg":"trace[2039836655] transaction","detail":"{read_only:false; response_revision:1212; number_of_response:1; }","duration":"101.995794ms","start":"2024-12-13T01:36:14.404321Z","end":"2024-12-13T01:36:14.506317Z","steps":["trace[2039836655] 'process raft request' (duration: 101.663067ms)"],"step_count":1} Dec 13 01:36:18.805389 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:18.805043Z","caller":"traceutil/trace.go:171","msg":"trace[542390658] transaction","detail":"{read_only:false; response_revision:1224; number_of_response:1; }","duration":"112.978415ms","start":"2024-12-13T01:36:18.692045Z","end":"2024-12-13T01:36:18.805023Z","steps":["trace[542390658] 'process raft request' (duration: 112.86481ms)"],"step_count":1} Dec 13 01:36:19.035343 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:19.034986Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"120.885124ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Dec 13 01:36:19.035343 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:19.035086Z","caller":"traceutil/trace.go:171","msg":"trace[1921283304] transaction","detail":"{read_only:false; response_revision:1225; number_of_response:1; }","duration":"275.059702ms","start":"2024-12-13T01:36:18.760009Z","end":"2024-12-13T01:36:19.035069Z","steps":["trace[1921283304] 'process raft request' (duration: 154.029275ms)","trace[1921283304] 'compare' (duration: 120.77767ms)"],"step_count":2} Dec 13 01:36:19.222863 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:19.222208Z","caller":"traceutil/trace.go:171","msg":"trace[2108034815] transaction","detail":"{read_only:false; response_revision:1226; number_of_response:1; }","duration":"411.891743ms","start":"2024-12-13T01:36:18.810294Z","end":"2024-12-13T01:36:19.222186Z","steps":["trace[2108034815] 'process raft request' (duration: 344.458749ms)","trace[2108034815] 'compare' (duration: 67.247604ms)"],"step_count":2} Dec 13 01:36:19.222863 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:19.222282Z","caller":"traceutil/trace.go:171","msg":"trace[353775335] transaction","detail":"{read_only:false; response_revision:1227; number_of_response:1; }","duration":"409.922825ms","start":"2024-12-13T01:36:18.812332Z","end":"2024-12-13T01:36:19.222254Z","steps":["trace[353775335] 'process raft request' (duration: 409.794893ms)"],"step_count":1} Dec 13 01:36:19.222863 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:19.222328Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-12-13T01:36:18.810268Z","time spent":"411.999506ms","remote":"10.0.0.100:53604","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1102,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Dec 13 01:36:19.222863 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:19.222228Z","caller":"traceutil/trace.go:171","msg":"trace[1802908959] transaction","detail":"{read_only:false; response_revision:1228; number_of_response:1; }","duration":"409.173218ms","start":"2024-12-13T01:36:18.813042Z","end":"2024-12-13T01:36:19.222215Z","steps":["trace[1802908959] 'process raft request' (duration: 409.125187ms)"],"step_count":1} Dec 13 01:36:19.223192 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:19.222420Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-12-13T01:36:18.813021Z","time spent":"409.384127ms","remote":"10.0.0.100:53726","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":1613,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Dec 13 01:36:19.223192 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:19.222417Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-12-13T01:36:18.812319Z","time spent":"410.028924ms","remote":"10.0.0.100:53886","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":4774,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Dec 13 01:36:22.500241 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:22.499883Z","caller":"traceutil/trace.go:171","msg":"trace[2082218976] linearizableReadLoop","detail":"{readStateIndex:1356; appliedIndex:1355; }","duration":"136.389053ms","start":"2024-12-13T01:36:22.363478Z","end":"2024-12-13T01:36:22.499867Z","steps":["trace[2082218976] 'read index received' (duration: 136.292581ms)","trace[2082218976] 'applied index is now lower than readState.Index' (duration: 95.971µs)"],"step_count":2} Dec 13 01:36:22.500241 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:22.499982Z","caller":"traceutil/trace.go:171","msg":"trace[437705710] transaction","detail":"{read_only:false; response_revision:1234; number_of_response:1; }","duration":"136.565797ms","start":"2024-12-13T01:36:22.363403Z","end":"2024-12-13T01:36:22.499968Z","steps":["trace[437705710] 'process raft request' (duration: 136.378994ms)"],"step_count":1} Dec 13 01:36:22.500241 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:22.500054Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"136.568933ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/default/nginx-deployment-8587fbcb89-t6lrm\" ","response":"range_response_count:1 size:3376"} Dec 13 01:36:22.500241 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:22.500080Z","caller":"traceutil/trace.go:171","msg":"trace[365940893] range","detail":"{range_begin:/registry/pods/default/nginx-deployment-8587fbcb89-t6lrm; range_end:; response_count:1; response_revision:1234; }","duration":"136.619929ms","start":"2024-12-13T01:36:22.363453Z","end":"2024-12-13T01:36:22.500072Z","steps":["trace[365940893] 'agreement among raft nodes before linearized reading' (duration: 136.506826ms)"],"step_count":1} Dec 13 01:36:23.481167 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:23.480836Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"207.278693ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Dec 13 01:36:23.481378 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:23.480913Z","caller":"traceutil/trace.go:171","msg":"trace[2011321054] linearizableReadLoop","detail":"{readStateIndex:1368; appliedIndex:1367; }","duration":"143.905028ms","start":"2024-12-13T01:36:23.336995Z","end":"2024-12-13T01:36:23.480900Z","steps":["trace[2011321054] 'read index received' (duration: 17.413µs)","trace[2011321054] 'applied index is now lower than readState.Index' (duration: 143.886783ms)"],"step_count":2} Dec 13 01:36:23.481378 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:23.480935Z","caller":"traceutil/trace.go:171","msg":"trace[762133379] transaction","detail":"{read_only:false; response_revision:1244; number_of_response:1; }","duration":"244.599155ms","start":"2024-12-13T01:36:23.236325Z","end":"2024-12-13T01:36:23.480924Z","steps":["trace[762133379] 'process raft request' (duration: 37.1763ms)","trace[762133379] 'compare' (duration: 207.199012ms)"],"step_count":2} Dec 13 01:36:23.481378 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:23.481014Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"144.024474ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/kube-scheduler-localhost.181098a5698f3944\" ","response":"range_response_count:1 size:817"} Dec 13 01:36:23.481378 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:23.481035Z","caller":"traceutil/trace.go:171","msg":"trace[1409192117] range","detail":"{range_begin:/registry/events/kube-system/kube-scheduler-localhost.181098a5698f3944; range_end:; response_count:1; response_revision:1244; }","duration":"144.067354ms","start":"2024-12-13T01:36:23.336960Z","end":"2024-12-13T01:36:23.481027Z","steps":["trace[1409192117] 'agreement among raft nodes before linearized reading' (duration: 143.992362ms)"],"step_count":1} Dec 13 01:36:24.387174 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:24.386837Z","caller":"traceutil/trace.go:171","msg":"trace[926657007] transaction","detail":"{read_only:false; response_revision:1247; number_of_response:1; }","duration":"132.954596ms","start":"2024-12-13T01:36:24.253864Z","end":"2024-12-13T01:36:24.386819Z","steps":["trace[926657007] 'process raft request' (duration: 132.802268ms)"],"step_count":1} Dec 13 01:36:27.490620 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:27.490200Z","caller":"traceutil/trace.go:171","msg":"trace[760443548] linearizableReadLoop","detail":"{readStateIndex:1381; appliedIndex:1380; }","duration":"212.05478ms","start":"2024-12-13T01:36:27.278123Z","end":"2024-12-13T01:36:27.490178Z","steps":["trace[760443548] 'read index received' (duration: 211.114245ms)","trace[760443548] 'applied index is now lower than readState.Index' (duration: 939.623µs)"],"step_count":2} Dec 13 01:36:27.490620 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:27.490240Z","caller":"traceutil/trace.go:171","msg":"trace[852621026] transaction","detail":"{read_only:false; response_revision:1256; number_of_response:1; }","duration":"217.566321ms","start":"2024-12-13T01:36:27.272642Z","end":"2024-12-13T01:36:27.490208Z","steps":["trace[852621026] 'process raft request' (duration: 216.629684ms)"],"step_count":1} Dec 13 01:36:27.490620 etcd-wrapper[1633]: {"level":"warn","ts":"2024-12-13T01:36:27.490377Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"212.252355ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/persistentvolumeclaims/default/test-dynamic-volume-claim\" ","response":"range_response_count:1 size:1720"} Dec 13 01:36:27.490620 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:27.490414Z","caller":"traceutil/trace.go:171","msg":"trace[109145774] range","detail":"{range_begin:/registry/persistentvolumeclaims/default/test-dynamic-volume-claim; range_end:; response_count:1; response_revision:1256; }","duration":"212.333416ms","start":"2024-12-13T01:36:27.278069Z","end":"2024-12-13T01:36:27.490403Z","steps":["trace[109145774] 'agreement among raft nodes before linearized reading' (duration: 212.198192ms)"],"step_count":1} Dec 13 01:36:27.492476 etcd-wrapper[1633]: {"level":"info","ts":"2024-12-13T01:36:27.492243Z","caller":"traceutil/trace.go:171","msg":"trace[1574900093] transaction","detail":"{read_only:false; response_revision:1257; number_of_response:1; }","duration":"213.091137ms","start":"2024-12-13T01:36:27.279135Z","end":"2024-12-13T01:36:27.492227Z","steps":["trace[1574900093] 'process raft request' (duration: 212.98685ms)"],"step_count":1}