Oct 8 19:56:16.983478 kernel: Linux version 6.6.54-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 Tue Oct 8 18:24:27 -00 2024 Oct 8 19:56:16.983508 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=ed527eaf992abc270af9987554566193214d123941456fd3066b47855e5178a5 Oct 8 19:56:16.983524 kernel: BIOS-provided physical RAM map: Oct 8 19:56:16.983532 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable Oct 8 19:56:16.983541 kernel: BIOS-e820: [mem 0x0000000000100000-0x00000000007fffff] usable Oct 8 19:56:16.983549 kernel: BIOS-e820: [mem 0x0000000000800000-0x0000000000807fff] ACPI NVS Oct 8 19:56:16.983560 kernel: BIOS-e820: [mem 0x0000000000808000-0x000000000080afff] usable Oct 8 19:56:16.983568 kernel: BIOS-e820: [mem 0x000000000080b000-0x000000000080bfff] ACPI NVS Oct 8 19:56:16.983577 kernel: BIOS-e820: [mem 0x000000000080c000-0x000000000080ffff] usable Oct 8 19:56:16.983586 kernel: BIOS-e820: [mem 0x0000000000810000-0x00000000008fffff] ACPI NVS Oct 8 19:56:16.983603 kernel: BIOS-e820: [mem 0x0000000000900000-0x000000009c8eefff] usable Oct 8 19:56:16.983612 kernel: BIOS-e820: [mem 0x000000009c8ef000-0x000000009c9eefff] reserved Oct 8 19:56:16.983621 kernel: BIOS-e820: [mem 0x000000009c9ef000-0x000000009caeefff] type 20 Oct 8 19:56:16.983630 kernel: BIOS-e820: [mem 0x000000009caef000-0x000000009cb6efff] reserved Oct 8 19:56:16.983659 kernel: BIOS-e820: [mem 0x000000009cb6f000-0x000000009cb7efff] ACPI data Oct 8 19:56:16.983673 kernel: BIOS-e820: [mem 0x000000009cb7f000-0x000000009cbfefff] ACPI NVS Oct 8 19:56:16.983687 kernel: BIOS-e820: [mem 0x000000009cbff000-0x000000009cf3ffff] usable Oct 8 19:56:16.983706 kernel: BIOS-e820: [mem 0x000000009cf40000-0x000000009cf5ffff] reserved Oct 8 19:56:16.983716 kernel: BIOS-e820: [mem 0x000000009cf60000-0x000000009cffffff] ACPI NVS Oct 8 19:56:16.983725 kernel: BIOS-e820: [mem 0x00000000b0000000-0x00000000bfffffff] reserved Oct 8 19:56:16.983734 kernel: NX (Execute Disable) protection: active Oct 8 19:56:16.983743 kernel: APIC: Static calls initialized Oct 8 19:56:16.983753 kernel: efi: EFI v2.7 by EDK II Oct 8 19:56:16.983762 kernel: efi: SMBIOS=0x9c9ab000 ACPI=0x9cb7e000 ACPI 2.0=0x9cb7e014 MEMATTR=0x9b674118 Oct 8 19:56:16.983771 kernel: SMBIOS 2.8 present. Oct 8 19:56:16.983781 kernel: DMI: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015 Oct 8 19:56:16.983789 kernel: Hypervisor detected: KVM Oct 8 19:56:16.983803 kernel: kvm-clock: Using msrs 4b564d01 and 4b564d00 Oct 8 19:56:16.983812 kernel: kvm-clock: using sched offset of 4606122486 cycles Oct 8 19:56:16.983822 kernel: clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns Oct 8 19:56:16.983832 kernel: tsc: Detected 2794.748 MHz processor Oct 8 19:56:16.983842 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Oct 8 19:56:16.983852 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Oct 8 19:56:16.983861 kernel: last_pfn = 0x9cf40 max_arch_pfn = 0x400000000 Oct 8 19:56:16.983871 kernel: MTRR map: 4 entries (2 fixed + 2 variable; max 18), built from 8 variable MTRRs Oct 8 19:56:16.983881 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Oct 8 19:56:16.983894 kernel: Using GB pages for direct mapping Oct 8 19:56:16.983903 kernel: Secure boot disabled Oct 8 19:56:16.983912 kernel: ACPI: Early table checksum verification disabled Oct 8 19:56:16.983922 kernel: ACPI: RSDP 0x000000009CB7E014 000024 (v02 BOCHS ) Oct 8 19:56:16.983942 kernel: ACPI: XSDT 0x000000009CB7D0E8 000054 (v01 BOCHS BXPC 00000001 01000013) Oct 8 19:56:16.983953 kernel: ACPI: FACP 0x000000009CB79000 0000F4 (v03 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.983964 kernel: ACPI: DSDT 0x000000009CB7A000 0021A8 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.983977 kernel: ACPI: FACS 0x000000009CBDD000 000040 Oct 8 19:56:16.983988 kernel: ACPI: APIC 0x000000009CB78000 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.983999 kernel: ACPI: HPET 0x000000009CB77000 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.984009 kernel: ACPI: MCFG 0x000000009CB76000 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.984020 kernel: ACPI: WAET 0x000000009CB75000 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) Oct 8 19:56:16.984030 kernel: ACPI: BGRT 0x000000009CB74000 000038 (v01 INTEL EDK2 00000002 01000013) Oct 8 19:56:16.984041 kernel: ACPI: Reserving FACP table memory at [mem 0x9cb79000-0x9cb790f3] Oct 8 19:56:16.984054 kernel: ACPI: Reserving DSDT table memory at [mem 0x9cb7a000-0x9cb7c1a7] Oct 8 19:56:16.984065 kernel: ACPI: Reserving FACS table memory at [mem 0x9cbdd000-0x9cbdd03f] Oct 8 19:56:16.984075 kernel: ACPI: Reserving APIC table memory at [mem 0x9cb78000-0x9cb7808f] Oct 8 19:56:16.984086 kernel: ACPI: Reserving HPET table memory at [mem 0x9cb77000-0x9cb77037] Oct 8 19:56:16.984096 kernel: ACPI: Reserving MCFG table memory at [mem 0x9cb76000-0x9cb7603b] Oct 8 19:56:16.984107 kernel: ACPI: Reserving WAET table memory at [mem 0x9cb75000-0x9cb75027] Oct 8 19:56:16.984117 kernel: ACPI: Reserving BGRT table memory at [mem 0x9cb74000-0x9cb74037] Oct 8 19:56:16.984130 kernel: No NUMA configuration found Oct 8 19:56:16.984141 kernel: Faking a node at [mem 0x0000000000000000-0x000000009cf3ffff] Oct 8 19:56:16.984154 kernel: NODE_DATA(0) allocated [mem 0x9cea6000-0x9ceabfff] Oct 8 19:56:16.984165 kernel: Zone ranges: Oct 8 19:56:16.984175 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Oct 8 19:56:16.984186 kernel: DMA32 [mem 0x0000000001000000-0x000000009cf3ffff] Oct 8 19:56:16.984196 kernel: Normal empty Oct 8 19:56:16.984207 kernel: Movable zone start for each node Oct 8 19:56:16.984217 kernel: Early memory node ranges Oct 8 19:56:16.984227 kernel: node 0: [mem 0x0000000000001000-0x000000000009ffff] Oct 8 19:56:16.984238 kernel: node 0: [mem 0x0000000000100000-0x00000000007fffff] Oct 8 19:56:16.984248 kernel: node 0: [mem 0x0000000000808000-0x000000000080afff] Oct 8 19:56:16.984262 kernel: node 0: [mem 0x000000000080c000-0x000000000080ffff] Oct 8 19:56:16.984272 kernel: node 0: [mem 0x0000000000900000-0x000000009c8eefff] Oct 8 19:56:16.984283 kernel: node 0: [mem 0x000000009cbff000-0x000000009cf3ffff] Oct 8 19:56:16.984293 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000009cf3ffff] Oct 8 19:56:16.984306 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Oct 8 19:56:16.984316 kernel: On node 0, zone DMA: 96 pages in unavailable ranges Oct 8 19:56:16.984327 kernel: On node 0, zone DMA: 8 pages in unavailable ranges Oct 8 19:56:16.984337 kernel: On node 0, zone DMA: 1 pages in unavailable ranges Oct 8 19:56:16.984347 kernel: On node 0, zone DMA: 240 pages in unavailable ranges Oct 8 19:56:16.984361 kernel: On node 0, zone DMA32: 784 pages in unavailable ranges Oct 8 19:56:16.984371 kernel: On node 0, zone DMA32: 12480 pages in unavailable ranges Oct 8 19:56:16.984382 kernel: ACPI: PM-Timer IO Port: 0x608 Oct 8 19:56:16.984392 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Oct 8 19:56:16.984403 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Oct 8 19:56:16.984414 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Oct 8 19:56:16.984424 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) Oct 8 19:56:16.984434 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Oct 8 19:56:16.984445 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) Oct 8 19:56:16.984458 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) Oct 8 19:56:16.984469 kernel: ACPI: Using ACPI (MADT) for SMP configuration information Oct 8 19:56:16.984479 kernel: ACPI: HPET id: 0x8086a201 base: 0xfed00000 Oct 8 19:56:16.984490 kernel: TSC deadline timer available Oct 8 19:56:16.984500 kernel: smpboot: Allowing 4 CPUs, 0 hotplug CPUs Oct 8 19:56:16.984510 kernel: kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() Oct 8 19:56:16.984521 kernel: kvm-guest: KVM setup pv remote TLB flush Oct 8 19:56:16.984531 kernel: kvm-guest: setup PV sched yield Oct 8 19:56:16.984541 kernel: [mem 0xc0000000-0xffffffff] available for PCI devices Oct 8 19:56:16.984552 kernel: Booting paravirtualized kernel on KVM Oct 8 19:56:16.984566 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns Oct 8 19:56:16.984576 kernel: setup_percpu: NR_CPUS:512 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 Oct 8 19:56:16.984587 kernel: percpu: Embedded 58 pages/cpu s196904 r8192 d32472 u524288 Oct 8 19:56:16.984597 kernel: pcpu-alloc: s196904 r8192 d32472 u524288 alloc=1*2097152 Oct 8 19:56:16.984608 kernel: pcpu-alloc: [0] 0 1 2 3 Oct 8 19:56:16.984618 kernel: kvm-guest: PV spinlocks enabled Oct 8 19:56:16.984629 kernel: PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) Oct 8 19:56:16.984659 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=ed527eaf992abc270af9987554566193214d123941456fd3066b47855e5178a5 Oct 8 19:56:16.984675 kernel: Unknown kernel command line parameters "BOOT_IMAGE=/flatcar/vmlinuz-a", will be passed to user space. Oct 8 19:56:16.984686 kernel: random: crng init done Oct 8 19:56:16.984696 kernel: Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Oct 8 19:56:16.984714 kernel: Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) Oct 8 19:56:16.984724 kernel: Fallback order for Node 0: 0 Oct 8 19:56:16.984735 kernel: Built 1 zonelists, mobility grouping on. Total pages: 629759 Oct 8 19:56:16.984745 kernel: Policy zone: DMA32 Oct 8 19:56:16.984756 kernel: mem auto-init: stack:off, heap alloc:off, heap free:off Oct 8 19:56:16.984767 kernel: Memory: 2395616K/2567000K available (12288K kernel code, 2305K rwdata, 22716K rodata, 42828K init, 2360K bss, 171124K reserved, 0K cma-reserved) Oct 8 19:56:16.984781 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Oct 8 19:56:16.984791 kernel: ftrace: allocating 37784 entries in 148 pages Oct 8 19:56:16.984801 kernel: ftrace: allocated 148 pages with 3 groups Oct 8 19:56:16.984812 kernel: Dynamic Preempt: voluntary Oct 8 19:56:16.984833 kernel: rcu: Preemptible hierarchical RCU implementation. Oct 8 19:56:16.984848 kernel: rcu: RCU event tracing is enabled. Oct 8 19:56:16.984859 kernel: rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4. Oct 8 19:56:16.984870 kernel: Trampoline variant of Tasks RCU enabled. Oct 8 19:56:16.984881 kernel: Rude variant of Tasks RCU enabled. Oct 8 19:56:16.984892 kernel: Tracing variant of Tasks RCU enabled. Oct 8 19:56:16.984903 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. Oct 8 19:56:16.984914 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 Oct 8 19:56:16.984928 kernel: NR_IRQS: 33024, nr_irqs: 456, preallocated irqs: 16 Oct 8 19:56:16.984939 kernel: rcu: srcu_init: Setting srcu_struct sizes based on contention. Oct 8 19:56:16.984950 kernel: Console: colour dummy device 80x25 Oct 8 19:56:16.984964 kernel: printk: console [ttyS0] enabled Oct 8 19:56:16.984976 kernel: ACPI: Core revision 20230628 Oct 8 19:56:16.984990 kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns Oct 8 19:56:16.985001 kernel: APIC: Switch to symmetric I/O mode setup Oct 8 19:56:16.985013 kernel: x2apic enabled Oct 8 19:56:16.985024 kernel: APIC: Switched APIC routing to: physical x2apic Oct 8 19:56:16.985035 kernel: kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() Oct 8 19:56:16.985045 kernel: kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() Oct 8 19:56:16.985056 kernel: kvm-guest: setup PV IPIs Oct 8 19:56:16.985068 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Oct 8 19:56:16.985079 kernel: tsc: Marking TSC unstable due to TSCs unsynchronized Oct 8 19:56:16.985093 kernel: Calibrating delay loop (skipped) preset value.. 5589.49 BogoMIPS (lpj=2794748) Oct 8 19:56:16.985105 kernel: x86/cpu: User Mode Instruction Prevention (UMIP) activated Oct 8 19:56:16.985115 kernel: Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127 Oct 8 19:56:16.985126 kernel: Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0 Oct 8 19:56:16.985137 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Oct 8 19:56:16.985148 kernel: Spectre V2 : Mitigation: Retpolines Oct 8 19:56:16.985160 kernel: Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch Oct 8 19:56:16.985171 kernel: Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT Oct 8 19:56:16.985181 kernel: Spectre V2 : Enabling Speculation Barrier for firmware calls Oct 8 19:56:16.985195 kernel: RETBleed: Mitigation: untrained return thunk Oct 8 19:56:16.985209 kernel: Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier Oct 8 19:56:16.985221 kernel: Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl Oct 8 19:56:16.985232 kernel: Speculative Return Stack Overflow: IBPB-extending microcode not applied! Oct 8 19:56:16.985244 kernel: Speculative Return Stack Overflow: WARNING: See https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for mitigation options. Oct 8 19:56:16.985255 kernel: Speculative Return Stack Overflow: Vulnerable: Safe RET, no microcode Oct 8 19:56:16.985266 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Oct 8 19:56:16.985277 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Oct 8 19:56:16.985291 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Oct 8 19:56:16.985302 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Oct 8 19:56:16.985314 kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format. Oct 8 19:56:16.985325 kernel: Freeing SMP alternatives memory: 32K Oct 8 19:56:16.985336 kernel: pid_max: default: 32768 minimum: 301 Oct 8 19:56:16.985347 kernel: LSM: initializing lsm=lockdown,capability,landlock,selinux,integrity Oct 8 19:56:16.985358 kernel: landlock: Up and running. Oct 8 19:56:16.985369 kernel: SELinux: Initializing. Oct 8 19:56:16.985380 kernel: Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 8 19:56:16.985394 kernel: Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) Oct 8 19:56:16.985405 kernel: smpboot: CPU0: AMD EPYC 7402P 24-Core Processor (family: 0x17, model: 0x31, stepping: 0x0) Oct 8 19:56:16.985416 kernel: RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. Oct 8 19:56:16.985427 kernel: RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. Oct 8 19:56:16.985438 kernel: RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. Oct 8 19:56:16.985449 kernel: Performance Events: Fam17h+ core perfctr, AMD PMU driver. Oct 8 19:56:16.985460 kernel: ... version: 0 Oct 8 19:56:16.985470 kernel: ... bit width: 48 Oct 8 19:56:16.985481 kernel: ... generic registers: 6 Oct 8 19:56:16.985495 kernel: ... value mask: 0000ffffffffffff Oct 8 19:56:16.985506 kernel: ... max period: 00007fffffffffff Oct 8 19:56:16.985517 kernel: ... fixed-purpose events: 0 Oct 8 19:56:16.985528 kernel: ... event mask: 000000000000003f Oct 8 19:56:16.985539 kernel: signal: max sigframe size: 1776 Oct 8 19:56:16.985549 kernel: rcu: Hierarchical SRCU implementation. Oct 8 19:56:16.985560 kernel: rcu: Max phase no-delay instances is 400. Oct 8 19:56:16.985571 kernel: smp: Bringing up secondary CPUs ... Oct 8 19:56:16.985582 kernel: smpboot: x86: Booting SMP configuration: Oct 8 19:56:16.985596 kernel: .... node #0, CPUs: #1 #2 #3 Oct 8 19:56:16.985607 kernel: smp: Brought up 1 node, 4 CPUs Oct 8 19:56:16.985618 kernel: smpboot: Max logical packages: 1 Oct 8 19:56:16.985629 kernel: smpboot: Total of 4 processors activated (22357.98 BogoMIPS) Oct 8 19:56:16.985655 kernel: devtmpfs: initialized Oct 8 19:56:16.985666 kernel: x86/mm: Memory block size: 128MB Oct 8 19:56:16.985677 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00800000-0x00807fff] (32768 bytes) Oct 8 19:56:16.985688 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x0080b000-0x0080bfff] (4096 bytes) Oct 8 19:56:16.985708 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x00810000-0x008fffff] (983040 bytes) Oct 8 19:56:16.985723 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cb7f000-0x9cbfefff] (524288 bytes) Oct 8 19:56:16.985735 kernel: ACPI: PM: Registering ACPI NVS region [mem 0x9cf60000-0x9cffffff] (655360 bytes) Oct 8 19:56:16.985745 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns Oct 8 19:56:16.985756 kernel: futex hash table entries: 1024 (order: 4, 65536 bytes, linear) Oct 8 19:56:16.985767 kernel: pinctrl core: initialized pinctrl subsystem Oct 8 19:56:16.985778 kernel: NET: Registered PF_NETLINK/PF_ROUTE protocol family Oct 8 19:56:16.985789 kernel: audit: initializing netlink subsys (disabled) Oct 8 19:56:16.985801 kernel: audit: type=2000 audit(1728417376.269:1): state=initialized audit_enabled=0 res=1 Oct 8 19:56:16.985811 kernel: thermal_sys: Registered thermal governor 'step_wise' Oct 8 19:56:16.985826 kernel: thermal_sys: Registered thermal governor 'user_space' Oct 8 19:56:16.985837 kernel: cpuidle: using governor menu Oct 8 19:56:16.985848 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Oct 8 19:56:16.985859 kernel: dca service started, version 1.12.1 Oct 8 19:56:16.985870 kernel: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xb0000000-0xbfffffff] (base 0xb0000000) Oct 8 19:56:16.985881 kernel: PCI: MMCONFIG at [mem 0xb0000000-0xbfffffff] reserved as E820 entry Oct 8 19:56:16.985892 kernel: PCI: Using configuration type 1 for base access Oct 8 19:56:16.985903 kernel: kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. Oct 8 19:56:16.985915 kernel: HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages Oct 8 19:56:16.985929 kernel: HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page Oct 8 19:56:16.985940 kernel: HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages Oct 8 19:56:16.985951 kernel: HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page Oct 8 19:56:16.985962 kernel: ACPI: Added _OSI(Module Device) Oct 8 19:56:16.985972 kernel: ACPI: Added _OSI(Processor Device) Oct 8 19:56:16.985983 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) Oct 8 19:56:16.985994 kernel: ACPI: Added _OSI(Processor Aggregator Device) Oct 8 19:56:16.986005 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Oct 8 19:56:16.986016 kernel: ACPI: _OSC evaluation for CPUs failed, trying _PDC Oct 8 19:56:16.986030 kernel: ACPI: Interpreter enabled Oct 8 19:56:16.986040 kernel: ACPI: PM: (supports S0 S3 S5) Oct 8 19:56:16.986051 kernel: ACPI: Using IOAPIC for interrupt routing Oct 8 19:56:16.986063 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Oct 8 19:56:16.986073 kernel: PCI: Using E820 reservations for host bridge windows Oct 8 19:56:16.986085 kernel: ACPI: Enabled 2 GPEs in block 00 to 3F Oct 8 19:56:16.986095 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Oct 8 19:56:16.986385 kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3] Oct 8 19:56:16.986569 kernel: acpi PNP0A08:00: _OSC: platform does not support [PCIeHotplug LTR] Oct 8 19:56:16.986909 kernel: acpi PNP0A08:00: _OSC: OS now controls [PME AER PCIeCapability] Oct 8 19:56:16.986927 kernel: PCI host bridge to bus 0000:00 Oct 8 19:56:16.987111 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Oct 8 19:56:16.987263 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Oct 8 19:56:16.987417 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Oct 8 19:56:16.987569 kernel: pci_bus 0000:00: root bus resource [mem 0x9d000000-0xafffffff window] Oct 8 19:56:16.987754 kernel: pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] Oct 8 19:56:16.987903 kernel: pci_bus 0000:00: root bus resource [mem 0x800000000-0xfffffffff window] Oct 8 19:56:16.988052 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Oct 8 19:56:16.988249 kernel: pci 0000:00:00.0: [8086:29c0] type 00 class 0x060000 Oct 8 19:56:16.988435 kernel: pci 0000:00:01.0: [1234:1111] type 00 class 0x030000 Oct 8 19:56:16.988602 kernel: pci 0000:00:01.0: reg 0x10: [mem 0xc0000000-0xc0ffffff pref] Oct 8 19:56:16.988815 kernel: pci 0000:00:01.0: reg 0x18: [mem 0xc1044000-0xc1044fff] Oct 8 19:56:16.988980 kernel: pci 0000:00:01.0: reg 0x30: [mem 0xffff0000-0xffffffff pref] Oct 8 19:56:16.989137 kernel: pci 0000:00:01.0: BAR 0: assigned to efifb Oct 8 19:56:16.989316 kernel: pci 0000:00:01.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Oct 8 19:56:16.989510 kernel: pci 0000:00:02.0: [1af4:1005] type 00 class 0x00ff00 Oct 8 19:56:16.989707 kernel: pci 0000:00:02.0: reg 0x10: [io 0x6100-0x611f] Oct 8 19:56:16.989881 kernel: pci 0000:00:02.0: reg 0x14: [mem 0xc1043000-0xc1043fff] Oct 8 19:56:16.990056 kernel: pci 0000:00:02.0: reg 0x20: [mem 0x800000000-0x800003fff 64bit pref] Oct 8 19:56:16.990246 kernel: pci 0000:00:03.0: [1af4:1001] type 00 class 0x010000 Oct 8 19:56:16.990417 kernel: pci 0000:00:03.0: reg 0x10: [io 0x6000-0x607f] Oct 8 19:56:16.990587 kernel: pci 0000:00:03.0: reg 0x14: [mem 0xc1042000-0xc1042fff] Oct 8 19:56:16.990786 kernel: pci 0000:00:03.0: reg 0x20: [mem 0x800004000-0x800007fff 64bit pref] Oct 8 19:56:16.990980 kernel: pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 Oct 8 19:56:16.991166 kernel: pci 0000:00:04.0: reg 0x10: [io 0x60e0-0x60ff] Oct 8 19:56:16.991348 kernel: pci 0000:00:04.0: reg 0x14: [mem 0xc1041000-0xc1041fff] Oct 8 19:56:16.991506 kernel: pci 0000:00:04.0: reg 0x20: [mem 0x800008000-0x80000bfff 64bit pref] Oct 8 19:56:16.991682 kernel: pci 0000:00:04.0: reg 0x30: [mem 0xfffc0000-0xffffffff pref] Oct 8 19:56:16.991897 kernel: pci 0000:00:1f.0: [8086:2918] type 00 class 0x060100 Oct 8 19:56:16.992053 kernel: pci 0000:00:1f.0: quirk: [io 0x0600-0x067f] claimed by ICH6 ACPI/GPIO/TCO Oct 8 19:56:16.992224 kernel: pci 0000:00:1f.2: [8086:2922] type 00 class 0x010601 Oct 8 19:56:16.992386 kernel: pci 0000:00:1f.2: reg 0x20: [io 0x60c0-0x60df] Oct 8 19:56:16.992541 kernel: pci 0000:00:1f.2: reg 0x24: [mem 0xc1040000-0xc1040fff] Oct 8 19:56:16.992739 kernel: pci 0000:00:1f.3: [8086:2930] type 00 class 0x0c0500 Oct 8 19:56:16.992898 kernel: pci 0000:00:1f.3: reg 0x20: [io 0x6080-0x60bf] Oct 8 19:56:16.992912 kernel: ACPI: PCI: Interrupt link LNKA configured for IRQ 10 Oct 8 19:56:16.992924 kernel: ACPI: PCI: Interrupt link LNKB configured for IRQ 10 Oct 8 19:56:16.992935 kernel: ACPI: PCI: Interrupt link LNKC configured for IRQ 11 Oct 8 19:56:16.992946 kernel: ACPI: PCI: Interrupt link LNKD configured for IRQ 11 Oct 8 19:56:16.992962 kernel: ACPI: PCI: Interrupt link LNKE configured for IRQ 10 Oct 8 19:56:16.992973 kernel: ACPI: PCI: Interrupt link LNKF configured for IRQ 10 Oct 8 19:56:16.992984 kernel: ACPI: PCI: Interrupt link LNKG configured for IRQ 11 Oct 8 19:56:16.992995 kernel: ACPI: PCI: Interrupt link LNKH configured for IRQ 11 Oct 8 19:56:16.993006 kernel: ACPI: PCI: Interrupt link GSIA configured for IRQ 16 Oct 8 19:56:16.993017 kernel: ACPI: PCI: Interrupt link GSIB configured for IRQ 17 Oct 8 19:56:16.993028 kernel: ACPI: PCI: Interrupt link GSIC configured for IRQ 18 Oct 8 19:56:16.993039 kernel: ACPI: PCI: Interrupt link GSID configured for IRQ 19 Oct 8 19:56:16.993050 kernel: ACPI: PCI: Interrupt link GSIE configured for IRQ 20 Oct 8 19:56:16.993064 kernel: ACPI: PCI: Interrupt link GSIF configured for IRQ 21 Oct 8 19:56:16.993075 kernel: ACPI: PCI: Interrupt link GSIG configured for IRQ 22 Oct 8 19:56:16.993086 kernel: ACPI: PCI: Interrupt link GSIH configured for IRQ 23 Oct 8 19:56:16.993097 kernel: iommu: Default domain type: Translated Oct 8 19:56:16.993108 kernel: iommu: DMA domain TLB invalidation policy: lazy mode Oct 8 19:56:16.993120 kernel: efivars: Registered efivars operations Oct 8 19:56:16.993131 kernel: PCI: Using ACPI for IRQ routing Oct 8 19:56:16.993142 kernel: PCI: pci_cache_line_size set to 64 bytes Oct 8 19:56:16.993153 kernel: e820: reserve RAM buffer [mem 0x0080b000-0x008fffff] Oct 8 19:56:16.993167 kernel: e820: reserve RAM buffer [mem 0x00810000-0x008fffff] Oct 8 19:56:16.993178 kernel: e820: reserve RAM buffer [mem 0x9c8ef000-0x9fffffff] Oct 8 19:56:16.993189 kernel: e820: reserve RAM buffer [mem 0x9cf40000-0x9fffffff] Oct 8 19:56:16.993342 kernel: pci 0000:00:01.0: vgaarb: setting as boot VGA device Oct 8 19:56:16.993510 kernel: pci 0000:00:01.0: vgaarb: bridge control possible Oct 8 19:56:16.993719 kernel: pci 0000:00:01.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Oct 8 19:56:16.993736 kernel: vgaarb: loaded Oct 8 19:56:16.993747 kernel: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 Oct 8 19:56:16.993757 kernel: hpet0: 3 comparators, 64-bit 100.000000 MHz counter Oct 8 19:56:16.993774 kernel: clocksource: Switched to clocksource kvm-clock Oct 8 19:56:16.993784 kernel: VFS: Disk quotas dquot_6.6.0 Oct 8 19:56:16.993796 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Oct 8 19:56:16.993807 kernel: pnp: PnP ACPI init Oct 8 19:56:16.994002 kernel: system 00:05: [mem 0xb0000000-0xbfffffff window] has been reserved Oct 8 19:56:16.994020 kernel: pnp: PnP ACPI: found 6 devices Oct 8 19:56:16.994031 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Oct 8 19:56:16.994042 kernel: NET: Registered PF_INET protocol family Oct 8 19:56:16.994058 kernel: IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) Oct 8 19:56:16.994069 kernel: tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) Oct 8 19:56:16.994080 kernel: Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) Oct 8 19:56:16.994091 kernel: TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) Oct 8 19:56:16.994102 kernel: TCP bind hash table entries: 32768 (order: 8, 1048576 bytes, linear) Oct 8 19:56:16.994113 kernel: TCP: Hash tables configured (established 32768 bind 32768) Oct 8 19:56:16.994124 kernel: UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 8 19:56:16.994135 kernel: UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) Oct 8 19:56:16.994146 kernel: NET: Registered PF_UNIX/PF_LOCAL protocol family Oct 8 19:56:16.994160 kernel: NET: Registered PF_XDP protocol family Oct 8 19:56:16.994329 kernel: pci 0000:00:04.0: can't claim BAR 6 [mem 0xfffc0000-0xffffffff pref]: no compatible bridge window Oct 8 19:56:16.994495 kernel: pci 0000:00:04.0: BAR 6: assigned [mem 0x9d000000-0x9d03ffff pref] Oct 8 19:56:16.994673 kernel: pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] Oct 8 19:56:16.994830 kernel: pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] Oct 8 19:56:16.994970 kernel: pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] Oct 8 19:56:16.995111 kernel: pci_bus 0000:00: resource 7 [mem 0x9d000000-0xafffffff window] Oct 8 19:56:16.995251 kernel: pci_bus 0000:00: resource 8 [mem 0xc0000000-0xfebfffff window] Oct 8 19:56:16.995398 kernel: pci_bus 0000:00: resource 9 [mem 0x800000000-0xfffffffff window] Oct 8 19:56:16.995412 kernel: PCI: CLS 0 bytes, default 64 Oct 8 19:56:16.995424 kernel: Initialise system trusted keyrings Oct 8 19:56:16.995435 kernel: workingset: timestamp_bits=39 max_order=20 bucket_order=0 Oct 8 19:56:16.995446 kernel: Key type asymmetric registered Oct 8 19:56:16.995457 kernel: Asymmetric key parser 'x509' registered Oct 8 19:56:16.995468 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251) Oct 8 19:56:16.995479 kernel: io scheduler mq-deadline registered Oct 8 19:56:16.995494 kernel: io scheduler kyber registered Oct 8 19:56:16.995504 kernel: io scheduler bfq registered Oct 8 19:56:16.995514 kernel: ioatdma: Intel(R) QuickData Technology Driver 5.00 Oct 8 19:56:16.995526 kernel: ACPI: \_SB_.GSIG: Enabled at IRQ 22 Oct 8 19:56:16.995537 kernel: ACPI: \_SB_.GSIH: Enabled at IRQ 23 Oct 8 19:56:16.995548 kernel: ACPI: \_SB_.GSIE: Enabled at IRQ 20 Oct 8 19:56:16.995560 kernel: Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled Oct 8 19:56:16.995571 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Oct 8 19:56:16.995583 kernel: i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 Oct 8 19:56:16.995594 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Oct 8 19:56:16.995609 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Oct 8 19:56:16.995908 kernel: rtc_cmos 00:04: RTC can wake from S4 Oct 8 19:56:16.995926 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0 Oct 8 19:56:16.996071 kernel: rtc_cmos 00:04: registered as rtc0 Oct 8 19:56:16.996215 kernel: rtc_cmos 00:04: setting system clock to 2024-10-08T19:56:16 UTC (1728417376) Oct 8 19:56:16.996358 kernel: rtc_cmos 00:04: alarms up to one day, y3k, 242 bytes nvram, hpet irqs Oct 8 19:56:16.996372 kernel: amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled Oct 8 19:56:16.996387 kernel: efifb: probing for efifb Oct 8 19:56:16.996398 kernel: efifb: framebuffer at 0xc0000000, using 1408k, total 1408k Oct 8 19:56:16.996408 kernel: efifb: mode is 800x600x24, linelength=2400, pages=1 Oct 8 19:56:16.996418 kernel: efifb: scrolling: redraw Oct 8 19:56:16.996428 kernel: efifb: Truecolor: size=0:8:8:8, shift=0:16:8:0 Oct 8 19:56:16.996438 kernel: Console: switching to colour frame buffer device 100x37 Oct 8 19:56:16.996472 kernel: fb0: EFI VGA frame buffer device Oct 8 19:56:16.996486 kernel: pstore: Using crash dump compression: deflate Oct 8 19:56:16.996497 kernel: pstore: Registered efi_pstore as persistent store backend Oct 8 19:56:16.996511 kernel: NET: Registered PF_INET6 protocol family Oct 8 19:56:16.996521 kernel: Segment Routing with IPv6 Oct 8 19:56:16.996532 kernel: In-situ OAM (IOAM) with IPv6 Oct 8 19:56:16.996542 kernel: NET: Registered PF_PACKET protocol family Oct 8 19:56:16.996553 kernel: Key type dns_resolver registered Oct 8 19:56:16.996564 kernel: IPI shorthand broadcast: enabled Oct 8 19:56:16.996575 kernel: sched_clock: Marking stable (1000005803, 120371848)->(1196678981, -76301330) Oct 8 19:56:16.996586 kernel: registered taskstats version 1 Oct 8 19:56:16.996596 kernel: Loading compiled-in X.509 certificates Oct 8 19:56:16.996607 kernel: Loaded X.509 cert 'Kinvolk GmbH: Module signing key for 6.6.54-flatcar: 14ce23fc5070d0471461f1dd6e298a5588e7ba8f' Oct 8 19:56:16.996621 kernel: Key type .fscrypt registered Oct 8 19:56:16.996632 kernel: Key type fscrypt-provisioning registered Oct 8 19:56:16.996657 kernel: ima: No TPM chip found, activating TPM-bypass! Oct 8 19:56:16.996668 kernel: ima: Allocated hash algorithm: sha1 Oct 8 19:56:16.996679 kernel: ima: No architecture policies found Oct 8 19:56:16.996690 kernel: clk: Disabling unused clocks Oct 8 19:56:16.996707 kernel: Freeing unused kernel image (initmem) memory: 42828K Oct 8 19:56:16.996719 kernel: Write protecting the kernel read-only data: 36864k Oct 8 19:56:16.996733 kernel: Freeing unused kernel image (rodata/data gap) memory: 1860K Oct 8 19:56:16.996744 kernel: Run /init as init process Oct 8 19:56:16.996755 kernel: with arguments: Oct 8 19:56:16.996766 kernel: /init Oct 8 19:56:16.996777 kernel: with environment: Oct 8 19:56:16.996787 kernel: HOME=/ Oct 8 19:56:16.996798 kernel: TERM=linux Oct 8 19:56:16.996812 kernel: BOOT_IMAGE=/flatcar/vmlinuz-a Oct 8 19:56:16.996826 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) Oct 8 19:56:16.996843 systemd[1]: Detected virtualization kvm. Oct 8 19:56:16.996855 systemd[1]: Detected architecture x86-64. Oct 8 19:56:16.996866 systemd[1]: Running in initrd. Oct 8 19:56:16.996881 systemd[1]: No hostname configured, using default hostname. Oct 8 19:56:16.996895 systemd[1]: Hostname set to . Oct 8 19:56:16.996907 systemd[1]: Initializing machine ID from VM UUID. Oct 8 19:56:16.996918 systemd[1]: Queued start job for default target initrd.target. Oct 8 19:56:16.996930 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:56:16.996942 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:56:16.996955 systemd[1]: Expecting device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM... Oct 8 19:56:16.996967 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 8 19:56:16.996979 systemd[1]: Expecting device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT... Oct 8 19:56:16.996993 systemd[1]: Expecting device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A... Oct 8 19:56:16.997008 systemd[1]: Expecting device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132... Oct 8 19:56:16.997020 systemd[1]: Expecting device dev-mapper-usr.device - /dev/mapper/usr... Oct 8 19:56:16.997032 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:56:16.997044 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:56:16.997055 systemd[1]: Reached target paths.target - Path Units. Oct 8 19:56:16.997067 systemd[1]: Reached target slices.target - Slice Units. Oct 8 19:56:16.997082 systemd[1]: Reached target swap.target - Swaps. Oct 8 19:56:16.997093 systemd[1]: Reached target timers.target - Timer Units. Oct 8 19:56:16.997105 systemd[1]: Listening on iscsid.socket - Open-iSCSI iscsid Socket. Oct 8 19:56:16.997117 systemd[1]: Listening on iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 8 19:56:16.997128 systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log). Oct 8 19:56:16.997140 systemd[1]: Listening on systemd-journald.socket - Journal Socket. Oct 8 19:56:16.997152 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:56:16.997164 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 8 19:56:16.997179 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:56:16.997190 systemd[1]: Reached target sockets.target - Socket Units. Oct 8 19:56:16.997202 systemd[1]: Starting ignition-setup-pre.service - Ignition env setup... Oct 8 19:56:16.997213 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 8 19:56:16.997224 systemd[1]: Finished network-cleanup.service - Network Cleanup. Oct 8 19:56:16.997236 systemd[1]: Starting systemd-fsck-usr.service... Oct 8 19:56:16.997247 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 8 19:56:16.997259 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 8 19:56:16.997270 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:56:16.997285 systemd[1]: Finished ignition-setup-pre.service - Ignition env setup. Oct 8 19:56:16.997296 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:56:16.997308 systemd[1]: Finished systemd-fsck-usr.service. Oct 8 19:56:16.997320 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 8 19:56:16.997363 systemd-journald[193]: Collecting audit messages is disabled. Oct 8 19:56:16.997391 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:56:16.997403 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 8 19:56:16.997415 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:16.997430 systemd-journald[193]: Journal started Oct 8 19:56:16.997454 systemd-journald[193]: Runtime Journal (/run/log/journal/70364a2776d84d5aa068becaca286328) is 6.0M, max 48.3M, 42.2M free. Oct 8 19:56:17.013665 systemd[1]: Started systemd-journald.service - Journal Service. Oct 8 19:56:17.015040 systemd-modules-load[194]: Inserted module 'overlay' Oct 8 19:56:17.019375 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:56:17.022271 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 8 19:56:17.029998 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:56:17.149672 kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. Oct 8 19:56:17.152326 systemd-modules-load[194]: Inserted module 'br_netfilter' Oct 8 19:56:17.153366 kernel: Bridge firewalling registered Oct 8 19:56:17.163055 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 8 19:56:17.164043 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:56:17.169449 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 8 19:56:17.186935 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:56:17.197878 systemd[1]: Starting dracut-cmdline.service - dracut cmdline hook... Oct 8 19:56:17.200201 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:56:17.204581 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 8 19:56:17.211411 dracut-cmdline[224]: dracut-dracut-053 Oct 8 19:56:17.214854 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=ed527eaf992abc270af9987554566193214d123941456fd3066b47855e5178a5 Oct 8 19:56:17.247047 systemd-resolved[230]: Positive Trust Anchors: Oct 8 19:56:17.247062 systemd-resolved[230]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 8 19:56:17.247094 systemd-resolved[230]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 8 19:56:17.258481 systemd-resolved[230]: Defaulting to hostname 'linux'. Oct 8 19:56:17.260653 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 8 19:56:17.261185 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:56:17.325702 kernel: SCSI subsystem initialized Oct 8 19:56:17.338678 kernel: Loading iSCSI transport class v2.0-870. Oct 8 19:56:17.352675 kernel: iscsi: registered transport (tcp) Oct 8 19:56:17.376685 kernel: iscsi: registered transport (qla4xxx) Oct 8 19:56:17.376765 kernel: QLogic iSCSI HBA Driver Oct 8 19:56:17.436451 systemd[1]: Finished dracut-cmdline.service - dracut cmdline hook. Oct 8 19:56:17.441842 systemd[1]: Starting dracut-pre-udev.service - dracut pre-udev hook... Oct 8 19:56:17.471460 kernel: device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. Oct 8 19:56:17.471542 kernel: device-mapper: uevent: version 1.0.3 Oct 8 19:56:17.471554 kernel: device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com Oct 8 19:56:17.514689 kernel: raid6: avx2x4 gen() 30057 MB/s Oct 8 19:56:17.531663 kernel: raid6: avx2x2 gen() 30336 MB/s Oct 8 19:56:17.549035 kernel: raid6: avx2x1 gen() 22526 MB/s Oct 8 19:56:17.549113 kernel: raid6: using algorithm avx2x2 gen() 30336 MB/s Oct 8 19:56:17.567009 kernel: raid6: .... xor() 17575 MB/s, rmw enabled Oct 8 19:56:17.567073 kernel: raid6: using avx2x2 recovery algorithm Oct 8 19:56:17.588703 kernel: xor: automatically using best checksumming function avx Oct 8 19:56:17.744687 kernel: Btrfs loaded, zoned=no, fsverity=no Oct 8 19:56:17.759978 systemd[1]: Finished dracut-pre-udev.service - dracut pre-udev hook. Oct 8 19:56:17.767832 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:56:17.783395 systemd-udevd[411]: Using default interface naming scheme 'v255'. Oct 8 19:56:17.788977 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:56:17.805851 systemd[1]: Starting dracut-pre-trigger.service - dracut pre-trigger hook... Oct 8 19:56:17.820533 dracut-pre-trigger[421]: rd.md=0: removing MD RAID activation Oct 8 19:56:17.857977 systemd[1]: Finished dracut-pre-trigger.service - dracut pre-trigger hook. Oct 8 19:56:17.872073 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 8 19:56:17.946035 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:56:17.955969 systemd[1]: Starting dracut-initqueue.service - dracut initqueue hook... Oct 8 19:56:17.971602 systemd[1]: Finished dracut-initqueue.service - dracut initqueue hook. Oct 8 19:56:17.973535 systemd[1]: Reached target remote-fs-pre.target - Preparation for Remote File Systems. Oct 8 19:56:17.976229 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:56:17.979114 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 8 19:56:17.987711 kernel: cryptd: max_cpu_qlen set to 1000 Oct 8 19:56:17.992169 systemd[1]: Starting dracut-pre-mount.service - dracut pre-mount hook... Oct 8 19:56:17.997662 kernel: AVX2 version of gcm_enc/dec engaged. Oct 8 19:56:17.997710 kernel: AES CTR mode by8 optimization enabled Oct 8 19:56:18.011659 kernel: virtio_blk virtio1: 4/0/0 default/read/poll queues Oct 8 19:56:18.014276 systemd[1]: Finished dracut-pre-mount.service - dracut pre-mount hook. Oct 8 19:56:18.019847 kernel: virtio_blk virtio1: [vda] 9289728 512-byte logical blocks (4.76 GB/4.43 GiB) Oct 8 19:56:18.022674 kernel: libata version 3.00 loaded. Oct 8 19:56:18.022706 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:56:18.024053 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Oct 8 19:56:18.024698 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:56:18.028333 systemd[1]: Stopping dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:56:18.034940 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 8 19:56:18.035280 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:18.036066 systemd[1]: Stopping systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:56:18.048679 kernel: BTRFS: device label OEM devid 1 transid 12 /dev/vda6 scanned by (udev-worker) (462) Oct 8 19:56:18.048735 kernel: ahci 0000:00:1f.2: version 3.0 Oct 8 19:56:18.050657 kernel: ACPI: \_SB_.GSIA: Enabled at IRQ 16 Oct 8 19:56:18.053341 kernel: ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode Oct 8 19:56:18.053595 kernel: BTRFS: device fsid a8680da2-059a-4648-a8e8-f62925ab33ec devid 1 transid 38 /dev/vda3 scanned by (udev-worker) (457) Oct 8 19:56:18.053613 kernel: ahci 0000:00:1f.2: flags: 64bit ncq only Oct 8 19:56:18.058736 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:56:18.064677 kernel: scsi host0: ahci Oct 8 19:56:18.064949 kernel: scsi host1: ahci Oct 8 19:56:18.065110 kernel: scsi host2: ahci Oct 8 19:56:18.065827 kernel: scsi host3: ahci Oct 8 19:56:18.066788 kernel: scsi host4: ahci Oct 8 19:56:18.069657 kernel: scsi host5: ahci Oct 8 19:56:18.069895 kernel: ata1: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040100 irq 34 Oct 8 19:56:18.069910 kernel: ata2: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040180 irq 34 Oct 8 19:56:18.069930 kernel: ata3: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040200 irq 34 Oct 8 19:56:18.070050 kernel: ata4: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040280 irq 34 Oct 8 19:56:18.071680 kernel: ata5: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040300 irq 34 Oct 8 19:56:18.071708 kernel: ata6: SATA max UDMA/133 abar m4096@0xc1040000 port 0xc1040380 irq 34 Oct 8 19:56:18.083798 systemd[1]: Found device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device - /dev/disk/by-label/EFI-SYSTEM. Oct 8 19:56:18.089729 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:18.097929 systemd[1]: Found device dev-disk-by\x2dlabel-ROOT.device - /dev/disk/by-label/ROOT. Oct 8 19:56:18.108580 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 8 19:56:18.114243 systemd[1]: Found device dev-disk-by\x2dpartuuid-7130c94a\x2d213a\x2d4e5a\x2d8e26\x2d6cce9662f132.device - /dev/disk/by-partuuid/7130c94a-213a-4e5a-8e26-6cce9662f132. Oct 8 19:56:18.115719 systemd[1]: Found device dev-disk-by\x2dpartlabel-USR\x2dA.device - /dev/disk/by-partlabel/USR-A. Oct 8 19:56:18.134892 systemd[1]: Starting disk-uuid.service - Generate new UUID for disk GPT if necessary... Oct 8 19:56:18.137364 systemd[1]: Starting dracut-cmdline-ask.service - dracut ask for additional cmdline parameters... Oct 8 19:56:18.144679 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:56:18.151688 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:56:18.167402 systemd[1]: Finished dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:56:18.386582 kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Oct 8 19:56:18.386698 kernel: ata4: SATA link down (SStatus 0 SControl 300) Oct 8 19:56:18.386713 kernel: ata2: SATA link down (SStatus 0 SControl 300) Oct 8 19:56:18.386727 kernel: ata1: SATA link down (SStatus 0 SControl 300) Oct 8 19:56:18.387682 kernel: ata6: SATA link down (SStatus 0 SControl 300) Oct 8 19:56:18.388682 kernel: ata5: SATA link down (SStatus 0 SControl 300) Oct 8 19:56:18.389681 kernel: ata3.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 Oct 8 19:56:18.391252 kernel: ata3.00: applying bridge limits Oct 8 19:56:18.391280 kernel: ata3.00: configured for UDMA/100 Oct 8 19:56:18.391710 kernel: scsi 2:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 Oct 8 19:56:18.436701 kernel: sr 2:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray Oct 8 19:56:18.437153 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Oct 8 19:56:18.451211 kernel: sr 2:0:0:0: Attached scsi CD-ROM sr0 Oct 8 19:56:19.201673 kernel: vda: vda1 vda2 vda3 vda4 vda6 vda7 vda9 Oct 8 19:56:19.201959 disk-uuid[568]: The operation has completed successfully. Oct 8 19:56:19.228877 systemd[1]: disk-uuid.service: Deactivated successfully. Oct 8 19:56:19.229012 systemd[1]: Finished disk-uuid.service - Generate new UUID for disk GPT if necessary. Oct 8 19:56:19.256811 systemd[1]: Starting verity-setup.service - Verity Setup for /dev/mapper/usr... Oct 8 19:56:19.261402 sh[594]: Success Oct 8 19:56:19.290681 kernel: device-mapper: verity: sha256 using implementation "sha256-ni" Oct 8 19:56:19.326412 systemd[1]: Found device dev-mapper-usr.device - /dev/mapper/usr. Oct 8 19:56:19.350400 systemd[1]: Mounting sysusr-usr.mount - /sysusr/usr... Oct 8 19:56:19.355806 systemd[1]: Finished verity-setup.service - Verity Setup for /dev/mapper/usr. Oct 8 19:56:19.368805 kernel: BTRFS info (device dm-0): first mount of filesystem a8680da2-059a-4648-a8e8-f62925ab33ec Oct 8 19:56:19.368863 kernel: BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm Oct 8 19:56:19.368874 kernel: BTRFS warning (device dm-0): 'nologreplay' is deprecated, use 'rescue=nologreplay' instead Oct 8 19:56:19.369825 kernel: BTRFS info (device dm-0): disabling log replay at mount time Oct 8 19:56:19.371276 kernel: BTRFS info (device dm-0): using free space tree Oct 8 19:56:19.376680 systemd[1]: Mounted sysusr-usr.mount - /sysusr/usr. Oct 8 19:56:19.378119 systemd[1]: afterburn-network-kargs.service - Afterburn Initrd Setup Network Kernel Arguments was skipped because no trigger condition checks were met. Oct 8 19:56:19.387861 systemd[1]: Starting ignition-setup.service - Ignition (setup)... Oct 8 19:56:19.389202 systemd[1]: Starting parse-ip-for-networkd.service - Write systemd-networkd units from cmdline... Oct 8 19:56:19.404863 kernel: BTRFS info (device vda6): first mount of filesystem bfaca09e-98f3-46e8-bdd8-6fce748bf2b6 Oct 8 19:56:19.404956 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 8 19:56:19.404973 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:56:19.409814 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:56:19.420838 systemd[1]: mnt-oem.mount: Deactivated successfully. Oct 8 19:56:19.422751 kernel: BTRFS info (device vda6): last unmount of filesystem bfaca09e-98f3-46e8-bdd8-6fce748bf2b6 Oct 8 19:56:19.432491 systemd[1]: Finished ignition-setup.service - Ignition (setup). Oct 8 19:56:19.442969 systemd[1]: Starting ignition-fetch-offline.service - Ignition (fetch-offline)... Oct 8 19:56:19.508936 ignition[689]: Ignition 2.19.0 Oct 8 19:56:19.508953 ignition[689]: Stage: fetch-offline Oct 8 19:56:19.509003 ignition[689]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:19.509020 ignition[689]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:19.509220 ignition[689]: parsed url from cmdline: "" Oct 8 19:56:19.509227 ignition[689]: no config URL provided Oct 8 19:56:19.509236 ignition[689]: reading system config file "/usr/lib/ignition/user.ign" Oct 8 19:56:19.509250 ignition[689]: no config at "/usr/lib/ignition/user.ign" Oct 8 19:56:19.509291 ignition[689]: op(1): [started] loading QEMU firmware config module Oct 8 19:56:19.509299 ignition[689]: op(1): executing: "modprobe" "qemu_fw_cfg" Oct 8 19:56:19.519345 ignition[689]: op(1): [finished] loading QEMU firmware config module Oct 8 19:56:19.520791 ignition[689]: parsing config with SHA512: f7d065f08a84e6247352bdaf28d7c59a3106099df2da0aa9466f3a60f0d9b268cea851f3f1dd52d616bee930a996ab0b5f3540b708cea84b0288d9617d77c2c3 Oct 8 19:56:19.529037 unknown[689]: fetched base config from "system" Oct 8 19:56:19.529059 unknown[689]: fetched user config from "qemu" Oct 8 19:56:19.529289 ignition[689]: fetch-offline: fetch-offline passed Oct 8 19:56:19.530269 ignition[689]: Ignition finished successfully Oct 8 19:56:19.532615 systemd[1]: Finished ignition-fetch-offline.service - Ignition (fetch-offline). Oct 8 19:56:19.554445 systemd[1]: Finished parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 8 19:56:19.566908 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 8 19:56:19.597246 systemd-networkd[785]: lo: Link UP Oct 8 19:56:19.597260 systemd-networkd[785]: lo: Gained carrier Oct 8 19:56:19.599469 systemd-networkd[785]: Enumeration completed Oct 8 19:56:19.599584 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 8 19:56:19.600037 systemd-networkd[785]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:56:19.600042 systemd-networkd[785]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 8 19:56:19.600190 systemd[1]: Reached target network.target - Network. Oct 8 19:56:19.600420 systemd[1]: ignition-fetch.service - Ignition (fetch) was skipped because of an unmet condition check (ConditionPathExists=!/run/ignition.json). Oct 8 19:56:19.601156 systemd-networkd[785]: eth0: Link UP Oct 8 19:56:19.601162 systemd-networkd[785]: eth0: Gained carrier Oct 8 19:56:19.601171 systemd-networkd[785]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:56:19.611178 systemd[1]: Starting ignition-kargs.service - Ignition (kargs)... Oct 8 19:56:19.620859 systemd-networkd[785]: eth0: DHCPv4 address 10.0.0.64/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 8 19:56:19.627168 ignition[787]: Ignition 2.19.0 Oct 8 19:56:19.627181 ignition[787]: Stage: kargs Oct 8 19:56:19.627354 ignition[787]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:19.627365 ignition[787]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:19.627972 ignition[787]: kargs: kargs passed Oct 8 19:56:19.628028 ignition[787]: Ignition finished successfully Oct 8 19:56:19.635745 systemd[1]: Finished ignition-kargs.service - Ignition (kargs). Oct 8 19:56:19.653014 systemd[1]: Starting ignition-disks.service - Ignition (disks)... Oct 8 19:56:19.669105 ignition[796]: Ignition 2.19.0 Oct 8 19:56:19.669121 ignition[796]: Stage: disks Oct 8 19:56:19.669349 ignition[796]: no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:19.669366 ignition[796]: no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:19.673382 ignition[796]: disks: disks passed Oct 8 19:56:19.674084 ignition[796]: Ignition finished successfully Oct 8 19:56:19.677272 systemd[1]: Finished ignition-disks.service - Ignition (disks). Oct 8 19:56:19.678717 systemd[1]: Reached target initrd-root-device.target - Initrd Root Device. Oct 8 19:56:19.680753 systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems. Oct 8 19:56:19.682034 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 8 19:56:19.682461 systemd[1]: Reached target sysinit.target - System Initialization. Oct 8 19:56:19.683027 systemd[1]: Reached target basic.target - Basic System. Oct 8 19:56:19.698937 systemd[1]: Starting systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT... Oct 8 19:56:19.715299 systemd-fsck[807]: ROOT: clean, 14/553520 files, 52654/553472 blocks Oct 8 19:56:19.726208 systemd[1]: Finished systemd-fsck-root.service - File System Check on /dev/disk/by-label/ROOT. Oct 8 19:56:19.736759 systemd[1]: Mounting sysroot.mount - /sysroot... Oct 8 19:56:19.827671 kernel: EXT4-fs (vda9): mounted filesystem 1df90f14-3ad0-4280-9b7d-a34f65d70e4d r/w with ordered data mode. Quota mode: none. Oct 8 19:56:19.828142 systemd[1]: Mounted sysroot.mount - /sysroot. Oct 8 19:56:19.829836 systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System. Oct 8 19:56:19.846829 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 8 19:56:19.849150 systemd[1]: Mounting sysroot-usr.mount - /sysroot/usr... Oct 8 19:56:19.851934 systemd[1]: flatcar-metadata-hostname.service - Flatcar Metadata Hostname Agent was skipped because no trigger condition checks were met. Oct 8 19:56:19.857068 kernel: BTRFS: device label OEM devid 1 transid 13 /dev/vda6 scanned by mount (815) Oct 8 19:56:19.851995 systemd[1]: ignition-remount-sysroot.service - Remount /sysroot read-write for Ignition was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/sysroot). Oct 8 19:56:19.865231 kernel: BTRFS info (device vda6): first mount of filesystem bfaca09e-98f3-46e8-bdd8-6fce748bf2b6 Oct 8 19:56:19.865265 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 8 19:56:19.865282 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:56:19.865315 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:56:19.852025 systemd[1]: Reached target ignition-diskful.target - Ignition Boot Disk Setup. Oct 8 19:56:19.859183 systemd[1]: Mounted sysroot-usr.mount - /sysroot/usr. Oct 8 19:56:19.866751 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 8 19:56:19.870119 systemd[1]: Starting initrd-setup-root.service - Root filesystem setup... Oct 8 19:56:19.915160 initrd-setup-root[839]: cut: /sysroot/etc/passwd: No such file or directory Oct 8 19:56:19.921881 initrd-setup-root[846]: cut: /sysroot/etc/group: No such file or directory Oct 8 19:56:19.926395 initrd-setup-root[853]: cut: /sysroot/etc/shadow: No such file or directory Oct 8 19:56:19.930864 initrd-setup-root[860]: cut: /sysroot/etc/gshadow: No such file or directory Oct 8 19:56:20.029205 systemd[1]: Finished initrd-setup-root.service - Root filesystem setup. Oct 8 19:56:20.037794 systemd[1]: Starting ignition-mount.service - Ignition (mount)... Oct 8 19:56:20.038808 systemd[1]: Starting sysroot-boot.service - /sysroot/boot... Oct 8 19:56:20.050685 kernel: BTRFS info (device vda6): last unmount of filesystem bfaca09e-98f3-46e8-bdd8-6fce748bf2b6 Oct 8 19:56:20.066488 systemd[1]: Finished sysroot-boot.service - /sysroot/boot. Oct 8 19:56:20.078123 ignition[929]: INFO : Ignition 2.19.0 Oct 8 19:56:20.078123 ignition[929]: INFO : Stage: mount Oct 8 19:56:20.080328 ignition[929]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:20.080328 ignition[929]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:20.080328 ignition[929]: INFO : mount: mount passed Oct 8 19:56:20.080328 ignition[929]: INFO : Ignition finished successfully Oct 8 19:56:20.081481 systemd[1]: Finished ignition-mount.service - Ignition (mount). Oct 8 19:56:20.088758 systemd[1]: Starting ignition-files.service - Ignition (files)... Oct 8 19:56:20.368719 systemd[1]: sysroot-oem.mount: Deactivated successfully. Oct 8 19:56:20.381974 systemd[1]: Mounting sysroot-oem.mount - /sysroot/oem... Oct 8 19:56:20.389684 kernel: BTRFS: device label OEM devid 1 transid 14 /dev/vda6 scanned by mount (941) Oct 8 19:56:20.391913 kernel: BTRFS info (device vda6): first mount of filesystem bfaca09e-98f3-46e8-bdd8-6fce748bf2b6 Oct 8 19:56:20.391941 kernel: BTRFS info (device vda6): using crc32c (crc32c-intel) checksum algorithm Oct 8 19:56:20.391958 kernel: BTRFS info (device vda6): using free space tree Oct 8 19:56:20.395675 kernel: BTRFS info (device vda6): auto enabling async discard Oct 8 19:56:20.396722 systemd[1]: Mounted sysroot-oem.mount - /sysroot/oem. Oct 8 19:56:20.421412 ignition[958]: INFO : Ignition 2.19.0 Oct 8 19:56:20.421412 ignition[958]: INFO : Stage: files Oct 8 19:56:20.423879 ignition[958]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:20.423879 ignition[958]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:20.423879 ignition[958]: DEBUG : files: compiled without relabeling support, skipping Oct 8 19:56:20.423879 ignition[958]: INFO : files: ensureUsers: op(1): [started] creating or modifying user "core" Oct 8 19:56:20.423879 ignition[958]: DEBUG : files: ensureUsers: op(1): executing: "usermod" "--root" "/sysroot" "core" Oct 8 19:56:20.432233 ignition[958]: INFO : files: ensureUsers: op(1): [finished] creating or modifying user "core" Oct 8 19:56:20.432233 ignition[958]: INFO : files: ensureUsers: op(2): [started] adding ssh keys to user "core" Oct 8 19:56:20.432233 ignition[958]: INFO : files: ensureUsers: op(2): [finished] adding ssh keys to user "core" Oct 8 19:56:20.432233 ignition[958]: INFO : files: createFilesystemsFiles: createFiles: op(3): [started] writing file "/sysroot/etc/flatcar/update.conf" Oct 8 19:56:20.432233 ignition[958]: INFO : files: createFilesystemsFiles: createFiles: op(3): [finished] writing file "/sysroot/etc/flatcar/update.conf" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(4): [started] processing unit "etcd-member.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(4): op(5): [started] writing systemd drop-in "20-clct-etcd-member.conf" at "/sysroot/etc/systemd/system/etcd-member.service.d/20-clct-etcd-member.conf" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(4): op(5): [finished] writing systemd drop-in "20-clct-etcd-member.conf" at "/sysroot/etc/systemd/system/etcd-member.service.d/20-clct-etcd-member.conf" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(4): [finished] processing unit "etcd-member.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(6): [started] processing unit "coreos-metadata.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(6): op(7): [started] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(6): op(7): [finished] writing unit "coreos-metadata.service" at "/sysroot/etc/systemd/system/coreos-metadata.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(6): [finished] processing unit "coreos-metadata.service" Oct 8 19:56:20.432233 ignition[958]: INFO : files: op(8): [started] setting preset to disabled for "coreos-metadata.service" Oct 8 19:56:20.425986 unknown[958]: wrote ssh authorized keys file for user: core Oct 8 19:56:20.465629 ignition[958]: INFO : files: op(8): op(9): [started] removing enablement symlink(s) for "coreos-metadata.service" Oct 8 19:56:20.465629 ignition[958]: INFO : files: op(8): op(9): [finished] removing enablement symlink(s) for "coreos-metadata.service" Oct 8 19:56:20.465629 ignition[958]: INFO : files: op(8): [finished] setting preset to disabled for "coreos-metadata.service" Oct 8 19:56:20.465629 ignition[958]: INFO : files: op(a): [started] setting preset to enabled for "etcd-member.service" Oct 8 19:56:20.465629 ignition[958]: INFO : files: op(a): [finished] setting preset to enabled for "etcd-member.service" Oct 8 19:56:20.465629 ignition[958]: INFO : files: createResultFile: createFiles: op(b): [started] writing file "/sysroot/etc/.ignition-result.json" Oct 8 19:56:20.465629 ignition[958]: INFO : files: createResultFile: createFiles: op(b): [finished] writing file "/sysroot/etc/.ignition-result.json" Oct 8 19:56:20.465629 ignition[958]: INFO : files: files passed Oct 8 19:56:20.465629 ignition[958]: INFO : Ignition finished successfully Oct 8 19:56:20.461839 systemd[1]: Finished ignition-files.service - Ignition (files). Oct 8 19:56:20.474825 systemd[1]: Starting ignition-quench.service - Ignition (record completion)... Oct 8 19:56:20.477084 systemd[1]: Starting initrd-setup-root-after-ignition.service - Root filesystem completion... Oct 8 19:56:20.480030 systemd[1]: ignition-quench.service: Deactivated successfully. Oct 8 19:56:20.491344 initrd-setup-root-after-ignition[985]: grep: /sysroot/oem/oem-release: No such file or directory Oct 8 19:56:20.480180 systemd[1]: Finished ignition-quench.service - Ignition (record completion). Oct 8 19:56:20.494584 initrd-setup-root-after-ignition[988]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:56:20.494584 initrd-setup-root-after-ignition[988]: grep: /sysroot/usr/share/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:56:20.494537 systemd[1]: Finished initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 8 19:56:20.503073 initrd-setup-root-after-ignition[992]: grep: /sysroot/etc/flatcar/enabled-sysext.conf: No such file or directory Oct 8 19:56:20.496413 systemd[1]: Reached target ignition-complete.target - Ignition Complete. Oct 8 19:56:20.511922 systemd[1]: Starting initrd-parse-etc.service - Mountpoints Configured in the Real Root... Oct 8 19:56:20.546400 systemd[1]: initrd-parse-etc.service: Deactivated successfully. Oct 8 19:56:20.546553 systemd[1]: Finished initrd-parse-etc.service - Mountpoints Configured in the Real Root. Oct 8 19:56:20.549554 systemd[1]: Reached target initrd-fs.target - Initrd File Systems. Oct 8 19:56:20.552191 systemd[1]: Reached target initrd.target - Initrd Default Target. Oct 8 19:56:20.553528 systemd[1]: dracut-mount.service - dracut mount hook was skipped because no trigger condition checks were met. Oct 8 19:56:20.554508 systemd[1]: Starting dracut-pre-pivot.service - dracut pre-pivot and cleanup hook... Oct 8 19:56:20.577909 systemd[1]: Finished dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 8 19:56:20.590869 systemd[1]: Starting initrd-cleanup.service - Cleaning Up and Shutting Down Daemons... Oct 8 19:56:20.602369 systemd[1]: Stopped target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:56:20.603961 systemd[1]: Stopped target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:56:20.606956 systemd[1]: Stopped target timers.target - Timer Units. Oct 8 19:56:20.609532 systemd[1]: dracut-pre-pivot.service: Deactivated successfully. Oct 8 19:56:20.609728 systemd[1]: Stopped dracut-pre-pivot.service - dracut pre-pivot and cleanup hook. Oct 8 19:56:20.612487 systemd[1]: Stopped target initrd.target - Initrd Default Target. Oct 8 19:56:20.614655 systemd[1]: Stopped target basic.target - Basic System. Oct 8 19:56:20.617246 systemd[1]: Stopped target ignition-complete.target - Ignition Complete. Oct 8 19:56:20.620002 systemd[1]: Stopped target ignition-diskful.target - Ignition Boot Disk Setup. Oct 8 19:56:20.622616 systemd[1]: Stopped target initrd-root-device.target - Initrd Root Device. Oct 8 19:56:20.625281 systemd[1]: Stopped target remote-fs.target - Remote File Systems. Oct 8 19:56:20.626080 systemd[1]: Stopped target remote-fs-pre.target - Preparation for Remote File Systems. Oct 8 19:56:20.626496 systemd[1]: Stopped target sysinit.target - System Initialization. Oct 8 19:56:20.627094 systemd[1]: Stopped target local-fs.target - Local File Systems. Oct 8 19:56:20.627508 systemd[1]: Stopped target swap.target - Swaps. Oct 8 19:56:20.628095 systemd[1]: dracut-pre-mount.service: Deactivated successfully. Oct 8 19:56:20.628250 systemd[1]: Stopped dracut-pre-mount.service - dracut pre-mount hook. Oct 8 19:56:20.629212 systemd[1]: Stopped target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:56:20.629614 systemd[1]: Stopped target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:56:20.629998 systemd[1]: clevis-luks-askpass.path: Deactivated successfully. Oct 8 19:56:20.630155 systemd[1]: Stopped clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:56:20.630649 systemd[1]: dracut-initqueue.service: Deactivated successfully. Oct 8 19:56:20.630765 systemd[1]: Stopped dracut-initqueue.service - dracut initqueue hook. Oct 8 19:56:20.631457 systemd[1]: ignition-fetch-offline.service: Deactivated successfully. Oct 8 19:56:20.631589 systemd[1]: Stopped ignition-fetch-offline.service - Ignition (fetch-offline). Oct 8 19:56:20.632176 systemd[1]: Stopped target paths.target - Path Units. Oct 8 19:56:20.632467 systemd[1]: systemd-ask-password-console.path: Deactivated successfully. Oct 8 19:56:20.635723 systemd[1]: Stopped systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:56:20.636228 systemd[1]: Stopped target slices.target - Slice Units. Oct 8 19:56:20.636425 systemd[1]: Stopped target sockets.target - Socket Units. Oct 8 19:56:20.636669 systemd[1]: iscsid.socket: Deactivated successfully. Oct 8 19:56:20.636789 systemd[1]: Closed iscsid.socket - Open-iSCSI iscsid Socket. Oct 8 19:56:20.637281 systemd[1]: iscsiuio.socket: Deactivated successfully. Oct 8 19:56:20.637376 systemd[1]: Closed iscsiuio.socket - Open-iSCSI iscsiuio Socket. Oct 8 19:56:20.638123 systemd[1]: initrd-setup-root-after-ignition.service: Deactivated successfully. Oct 8 19:56:20.638243 systemd[1]: Stopped initrd-setup-root-after-ignition.service - Root filesystem completion. Oct 8 19:56:20.638775 systemd[1]: ignition-files.service: Deactivated successfully. Oct 8 19:56:20.670961 ignition[1012]: INFO : Ignition 2.19.0 Oct 8 19:56:20.670961 ignition[1012]: INFO : Stage: umount Oct 8 19:56:20.670961 ignition[1012]: INFO : no configs at "/usr/lib/ignition/base.d" Oct 8 19:56:20.670961 ignition[1012]: INFO : no config dir at "/usr/lib/ignition/base.platform.d/qemu" Oct 8 19:56:20.638894 systemd[1]: Stopped ignition-files.service - Ignition (files). Oct 8 19:56:20.672433 ignition[1012]: INFO : umount: umount passed Oct 8 19:56:20.672433 ignition[1012]: INFO : Ignition finished successfully Oct 8 19:56:20.655024 systemd[1]: Stopping ignition-mount.service - Ignition (mount)... Oct 8 19:56:20.658092 systemd[1]: Stopping sysroot-boot.service - /sysroot/boot... Oct 8 19:56:20.659226 systemd[1]: systemd-udev-trigger.service: Deactivated successfully. Oct 8 19:56:20.659468 systemd[1]: Stopped systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:56:20.662033 systemd[1]: dracut-pre-trigger.service: Deactivated successfully. Oct 8 19:56:20.662263 systemd[1]: Stopped dracut-pre-trigger.service - dracut pre-trigger hook. Oct 8 19:56:20.705900 systemd[1]: sysroot-boot.mount: Deactivated successfully. Oct 8 19:56:20.708129 systemd[1]: ignition-mount.service: Deactivated successfully. Oct 8 19:56:20.708320 systemd[1]: Stopped ignition-mount.service - Ignition (mount). Oct 8 19:56:20.712715 systemd[1]: sysroot-boot.service: Deactivated successfully. Oct 8 19:56:20.714139 systemd[1]: Stopped sysroot-boot.service - /sysroot/boot. Oct 8 19:56:20.719061 systemd[1]: initrd-cleanup.service: Deactivated successfully. Oct 8 19:56:20.720403 systemd[1]: Finished initrd-cleanup.service - Cleaning Up and Shutting Down Daemons. Oct 8 19:56:20.726120 systemd[1]: Stopped target network.target - Network. Oct 8 19:56:20.728402 systemd[1]: ignition-disks.service: Deactivated successfully. Oct 8 19:56:20.729550 systemd[1]: Stopped ignition-disks.service - Ignition (disks). Oct 8 19:56:20.732089 systemd[1]: ignition-kargs.service: Deactivated successfully. Oct 8 19:56:20.732182 systemd[1]: Stopped ignition-kargs.service - Ignition (kargs). Oct 8 19:56:20.735563 systemd[1]: ignition-setup.service: Deactivated successfully. Oct 8 19:56:20.736738 systemd[1]: Stopped ignition-setup.service - Ignition (setup). Oct 8 19:56:20.739090 systemd[1]: ignition-setup-pre.service: Deactivated successfully. Oct 8 19:56:20.740359 systemd[1]: Stopped ignition-setup-pre.service - Ignition env setup. Oct 8 19:56:20.742945 systemd[1]: initrd-setup-root.service: Deactivated successfully. Oct 8 19:56:20.743023 systemd[1]: Stopped initrd-setup-root.service - Root filesystem setup. Oct 8 19:56:20.746904 systemd[1]: Stopping systemd-networkd.service - Network Configuration... Oct 8 19:56:20.749564 systemd[1]: Stopping systemd-resolved.service - Network Name Resolution... Oct 8 19:56:20.750685 systemd-networkd[785]: eth0: DHCPv6 lease lost Oct 8 19:56:20.753304 systemd[1]: systemd-networkd.service: Deactivated successfully. Oct 8 19:56:20.754609 systemd[1]: Stopped systemd-networkd.service - Network Configuration. Oct 8 19:56:20.758281 systemd[1]: systemd-networkd.socket: Deactivated successfully. Oct 8 19:56:20.758366 systemd[1]: Closed systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:56:20.783790 systemd[1]: Stopping network-cleanup.service - Network Cleanup... Oct 8 19:56:20.784948 systemd[1]: parse-ip-for-networkd.service: Deactivated successfully. Oct 8 19:56:20.786239 systemd[1]: Stopped parse-ip-for-networkd.service - Write systemd-networkd units from cmdline. Oct 8 19:56:20.790741 systemd[1]: Stopping systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:56:20.794013 systemd[1]: systemd-resolved.service: Deactivated successfully. Oct 8 19:56:20.795227 systemd[1]: Stopped systemd-resolved.service - Network Name Resolution. Oct 8 19:56:20.814076 systemd[1]: systemd-udevd.service: Deactivated successfully. Oct 8 19:56:20.815440 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:56:20.819182 systemd[1]: network-cleanup.service: Deactivated successfully. Oct 8 19:56:20.820406 systemd[1]: Stopped network-cleanup.service - Network Cleanup. Oct 8 19:56:20.825471 systemd[1]: systemd-udevd-control.socket: Deactivated successfully. Oct 8 19:56:20.825569 systemd[1]: Closed systemd-udevd-control.socket - udev Control Socket. Oct 8 19:56:20.829310 systemd[1]: systemd-udevd-kernel.socket: Deactivated successfully. Oct 8 19:56:20.829366 systemd[1]: Closed systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:56:20.832982 systemd[1]: dracut-pre-udev.service: Deactivated successfully. Oct 8 19:56:20.834090 systemd[1]: Stopped dracut-pre-udev.service - dracut pre-udev hook. Oct 8 19:56:20.836615 systemd[1]: dracut-cmdline.service: Deactivated successfully. Oct 8 19:56:20.837749 systemd[1]: Stopped dracut-cmdline.service - dracut cmdline hook. Oct 8 19:56:20.840326 systemd[1]: dracut-cmdline-ask.service: Deactivated successfully. Oct 8 19:56:20.840399 systemd[1]: Stopped dracut-cmdline-ask.service - dracut ask for additional cmdline parameters. Oct 8 19:56:20.856976 systemd[1]: Starting initrd-udevadm-cleanup-db.service - Cleanup udev Database... Oct 8 19:56:20.857561 systemd[1]: systemd-sysctl.service: Deactivated successfully. Oct 8 19:56:20.857702 systemd[1]: Stopped systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:56:20.858249 systemd[1]: systemd-modules-load.service: Deactivated successfully. Oct 8 19:56:20.858304 systemd[1]: Stopped systemd-modules-load.service - Load Kernel Modules. Oct 8 19:56:20.858553 systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully. Oct 8 19:56:20.858616 systemd[1]: Stopped systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:56:20.864381 systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully. Oct 8 19:56:20.864460 systemd[1]: Stopped systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:56:20.865258 systemd[1]: kmod-static-nodes.service: Deactivated successfully. Oct 8 19:56:20.865314 systemd[1]: Stopped kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:56:20.865582 systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully. Oct 8 19:56:20.865661 systemd[1]: Stopped systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:56:20.866104 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 8 19:56:20.866149 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:20.867028 systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully. Oct 8 19:56:20.867148 systemd[1]: Finished initrd-udevadm-cleanup-db.service - Cleanup udev Database. Oct 8 19:56:20.877131 systemd[1]: Reached target initrd-switch-root.target - Switch Root. Oct 8 19:56:20.884547 systemd[1]: Starting initrd-switch-root.service - Switch Root... Oct 8 19:56:20.902317 systemd[1]: Switching root. Oct 8 19:56:21.105180 systemd-journald[193]: Journal stopped Oct 8 19:56:22.410434 systemd-journald[193]: Received SIGTERM from PID 1 (systemd). Oct 8 19:56:22.410516 kernel: SELinux: policy capability network_peer_controls=1 Oct 8 19:56:22.410535 kernel: SELinux: policy capability open_perms=1 Oct 8 19:56:22.410557 kernel: SELinux: policy capability extended_socket_class=1 Oct 8 19:56:22.410578 kernel: SELinux: policy capability always_check_network=0 Oct 8 19:56:22.410595 kernel: SELinux: policy capability cgroup_seclabel=1 Oct 8 19:56:22.410609 kernel: SELinux: policy capability nnp_nosuid_transition=1 Oct 8 19:56:22.410627 kernel: SELinux: policy capability genfs_seclabel_symlinks=0 Oct 8 19:56:22.410657 kernel: SELinux: policy capability ioctl_skip_cloexec=0 Oct 8 19:56:22.410674 kernel: audit: type=1403 audit(1728417381.392:2): auid=4294967295 ses=4294967295 lsm=selinux res=1 Oct 8 19:56:22.410693 systemd[1]: Successfully loaded SELinux policy in 42.521ms. Oct 8 19:56:22.410720 systemd[1]: Relabeled /dev, /dev/shm, /run, /sys/fs/cgroup in 15.084ms. Oct 8 19:56:22.410733 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) Oct 8 19:56:22.410749 systemd[1]: Detected virtualization kvm. Oct 8 19:56:22.410765 systemd[1]: Detected architecture x86-64. Oct 8 19:56:22.410782 systemd[1]: Detected first boot. Oct 8 19:56:22.410795 systemd[1]: Initializing machine ID from VM UUID. Oct 8 19:56:22.410809 zram_generator::config[1056]: No configuration found. Oct 8 19:56:22.410822 systemd[1]: Populated /etc with preset unit settings. Oct 8 19:56:22.410834 systemd[1]: initrd-switch-root.service: Deactivated successfully. Oct 8 19:56:22.410847 systemd[1]: Stopped initrd-switch-root.service - Switch Root. Oct 8 19:56:22.410872 systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. Oct 8 19:56:22.410886 systemd[1]: Created slice system-addon\x2dconfig.slice - Slice /system/addon-config. Oct 8 19:56:22.410898 systemd[1]: Created slice system-addon\x2drun.slice - Slice /system/addon-run. Oct 8 19:56:22.410910 systemd[1]: Created slice system-getty.slice - Slice /system/getty. Oct 8 19:56:22.410928 systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe. Oct 8 19:56:22.410942 systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Oct 8 19:56:22.410962 systemd[1]: Created slice system-system\x2dcloudinit.slice - Slice /system/system-cloudinit. Oct 8 19:56:22.410974 systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck. Oct 8 19:56:22.410986 systemd[1]: Created slice user.slice - User and Session Slice. Oct 8 19:56:22.410998 systemd[1]: Started clevis-luks-askpass.path - Forward Password Requests to Clevis Directory Watch. Oct 8 19:56:22.411011 systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch. Oct 8 19:56:22.411023 systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch. Oct 8 19:56:22.411041 systemd[1]: Set up automount boot.automount - Boot partition Automount Point. Oct 8 19:56:22.411053 systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point. Oct 8 19:56:22.411069 systemd[1]: Expecting device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM... Oct 8 19:56:22.411081 systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0... Oct 8 19:56:22.411093 systemd[1]: Reached target cryptsetup-pre.target - Local Encrypted Volumes (Pre). Oct 8 19:56:22.411107 systemd[1]: Stopped target initrd-switch-root.target - Switch Root. Oct 8 19:56:22.411119 systemd[1]: Stopped target initrd-fs.target - Initrd File Systems. Oct 8 19:56:22.411131 systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System. Oct 8 19:56:22.411143 systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes. Oct 8 19:56:22.411155 systemd[1]: Reached target remote-cryptsetup.target - Remote Encrypted Volumes. Oct 8 19:56:22.411176 systemd[1]: Reached target remote-fs.target - Remote File Systems. Oct 8 19:56:22.411189 systemd[1]: Reached target slices.target - Slice Units. Oct 8 19:56:22.411201 systemd[1]: Reached target swap.target - Swaps. Oct 8 19:56:22.411213 systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes. Oct 8 19:56:22.411225 systemd[1]: Listening on systemd-coredump.socket - Process Core Dump Socket. Oct 8 19:56:22.411237 systemd[1]: Listening on systemd-networkd.socket - Network Service Netlink Socket. Oct 8 19:56:22.411249 systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket. Oct 8 19:56:22.411261 systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket. Oct 8 19:56:22.411273 systemd[1]: Listening on systemd-userdbd.socket - User Database Manager Socket. Oct 8 19:56:22.411285 systemd[1]: Mounting dev-hugepages.mount - Huge Pages File System... Oct 8 19:56:22.411301 systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System... Oct 8 19:56:22.411313 systemd[1]: Mounting media.mount - External Media Directory... Oct 8 19:56:22.411325 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:22.411337 systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System... Oct 8 19:56:22.411349 systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System... Oct 8 19:56:22.411361 systemd[1]: Mounting tmp.mount - Temporary Directory /tmp... Oct 8 19:56:22.411375 systemd[1]: var-lib-machines.mount - Virtual Machine and Container Storage (Compatibility) was skipped because of an unmet condition check (ConditionPathExists=/var/lib/machines.raw). Oct 8 19:56:22.411387 systemd[1]: Reached target machines.target - Containers. Oct 8 19:56:22.411402 systemd[1]: Starting flatcar-tmpfiles.service - Create missing system files... Oct 8 19:56:22.411416 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:56:22.411428 systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes... Oct 8 19:56:22.411443 systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs... Oct 8 19:56:22.411460 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:56:22.411478 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 8 19:56:22.411491 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:56:22.411503 systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse... Oct 8 19:56:22.411519 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:56:22.411532 systemd[1]: setup-nsswitch.service - Create /etc/nsswitch.conf was skipped because of an unmet condition check (ConditionPathExists=!/etc/nsswitch.conf). Oct 8 19:56:22.411552 systemd[1]: systemd-fsck-root.service: Deactivated successfully. Oct 8 19:56:22.411564 systemd[1]: Stopped systemd-fsck-root.service - File System Check on Root Device. Oct 8 19:56:22.411576 systemd[1]: systemd-fsck-usr.service: Deactivated successfully. Oct 8 19:56:22.411588 systemd[1]: Stopped systemd-fsck-usr.service. Oct 8 19:56:22.411600 kernel: fuse: init (API version 7.39) Oct 8 19:56:22.411612 systemd[1]: Starting systemd-journald.service - Journal Service... Oct 8 19:56:22.411625 kernel: loop: module loaded Oct 8 19:56:22.411654 systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules... Oct 8 19:56:22.411667 systemd[1]: Starting systemd-network-generator.service - Generate network units from Kernel command line... Oct 8 19:56:22.411681 systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems... Oct 8 19:56:22.411693 systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices... Oct 8 19:56:22.411726 systemd-journald[1126]: Collecting audit messages is disabled. Oct 8 19:56:22.411749 systemd[1]: verity-setup.service: Deactivated successfully. Oct 8 19:56:22.411765 systemd[1]: Stopped verity-setup.service. Oct 8 19:56:22.411781 systemd-journald[1126]: Journal started Oct 8 19:56:22.411807 systemd-journald[1126]: Runtime Journal (/run/log/journal/70364a2776d84d5aa068becaca286328) is 6.0M, max 48.3M, 42.2M free. Oct 8 19:56:22.163546 systemd[1]: Queued start job for default target multi-user.target. Oct 8 19:56:22.181085 systemd[1]: Unnecessary job was removed for dev-vda6.device - /dev/vda6. Oct 8 19:56:22.181705 systemd[1]: systemd-journald.service: Deactivated successfully. Oct 8 19:56:22.415663 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:22.417665 kernel: ACPI: bus type drm_connector registered Oct 8 19:56:22.419668 systemd[1]: Started systemd-journald.service - Journal Service. Oct 8 19:56:22.420759 systemd[1]: Mounted dev-hugepages.mount - Huge Pages File System. Oct 8 19:56:22.421952 systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System. Oct 8 19:56:22.423162 systemd[1]: Mounted media.mount - External Media Directory. Oct 8 19:56:22.424326 systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System. Oct 8 19:56:22.425570 systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System. Oct 8 19:56:22.426817 systemd[1]: Mounted tmp.mount - Temporary Directory /tmp. Oct 8 19:56:22.428094 systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes. Oct 8 19:56:22.429757 systemd[1]: modprobe@configfs.service: Deactivated successfully. Oct 8 19:56:22.429956 systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs. Oct 8 19:56:22.431478 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:56:22.431722 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:56:22.433175 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 8 19:56:22.433359 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 8 19:56:22.434821 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:56:22.435000 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:56:22.436556 systemd[1]: modprobe@fuse.service: Deactivated successfully. Oct 8 19:56:22.436768 systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse. Oct 8 19:56:22.438228 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:56:22.438407 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:56:22.439971 systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules. Oct 8 19:56:22.442072 systemd[1]: Finished systemd-network-generator.service - Generate network units from Kernel command line. Oct 8 19:56:22.443653 systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems. Oct 8 19:56:22.461722 systemd[1]: Finished flatcar-tmpfiles.service - Create missing system files. Oct 8 19:56:22.464739 systemd[1]: Reached target network-pre.target - Preparation for Network. Oct 8 19:56:22.476864 systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System... Oct 8 19:56:22.480023 systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System... Oct 8 19:56:22.481379 systemd[1]: remount-root.service - Remount Root File System was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/). Oct 8 19:56:22.481416 systemd[1]: Reached target local-fs.target - Local File Systems. Oct 8 19:56:22.483671 systemd[1]: Listening on systemd-sysext.socket - System Extension Image Management (Varlink). Oct 8 19:56:22.486494 systemd[1]: Starting dracut-shutdown.service - Restore /run/initramfs on shutdown... Oct 8 19:56:22.492058 systemd[1]: Starting ldconfig.service - Rebuild Dynamic Linker Cache... Oct 8 19:56:22.493882 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:56:22.497422 systemd[1]: Starting systemd-hwdb-update.service - Rebuild Hardware Database... Oct 8 19:56:22.503342 systemd[1]: Starting systemd-journal-flush.service - Flush Journal to Persistent Storage... Oct 8 19:56:22.505116 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 8 19:56:22.519035 systemd[1]: Starting systemd-random-seed.service - Load/Save OS Random Seed... Oct 8 19:56:22.520549 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 8 19:56:22.526001 systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables... Oct 8 19:56:22.533381 systemd[1]: Starting systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/... Oct 8 19:56:22.540694 systemd[1]: Starting systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully... Oct 8 19:56:22.543358 systemd-journald[1126]: Time spent on flushing to /var/log/journal/70364a2776d84d5aa068becaca286328 is 23.159ms for 965 entries. Oct 8 19:56:22.543358 systemd-journald[1126]: System Journal (/var/log/journal/70364a2776d84d5aa068becaca286328) is 8.0M, max 195.6M, 187.6M free. Oct 8 19:56:22.579971 systemd-journald[1126]: Received client request to flush runtime journal. Oct 8 19:56:22.580005 kernel: loop0: detected capacity change from 0 to 142488 Oct 8 19:56:22.545405 systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices. Oct 8 19:56:22.548126 systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System. Oct 8 19:56:22.550371 systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System. Oct 8 19:56:22.551755 systemd[1]: Finished dracut-shutdown.service - Restore /run/initramfs on shutdown. Oct 8 19:56:22.552752 systemd[1]: Finished systemd-random-seed.service - Load/Save OS Random Seed. Oct 8 19:56:22.563788 systemd[1]: Reached target first-boot-complete.target - First Boot Complete. Oct 8 19:56:22.567968 systemd[1]: Starting systemd-machine-id-commit.service - Commit a transient machine-id on disk... Oct 8 19:56:22.572612 systemd[1]: Starting systemd-udev-settle.service - Wait for udev To Complete Device Initialization... Oct 8 19:56:22.575448 systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables. Oct 8 19:56:22.583872 systemd[1]: Finished systemd-journal-flush.service - Flush Journal to Persistent Storage. Oct 8 19:56:22.589800 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Oct 8 19:56:22.603838 udevadm[1181]: systemd-udev-settle.service is deprecated. Please fix lvm2-activation.service, lvm2-activation-early.service not to pull it in. Oct 8 19:56:22.607320 systemd-tmpfiles[1171]: ACLs are not supported, ignoring. Oct 8 19:56:22.607340 systemd-tmpfiles[1171]: ACLs are not supported, ignoring. Oct 8 19:56:22.615374 systemd[1]: etc-machine\x2did.mount: Deactivated successfully. Oct 8 19:56:22.616401 systemd[1]: Finished systemd-tmpfiles-setup-dev-early.service - Create Static Device Nodes in /dev gracefully. Oct 8 19:56:22.618206 systemd[1]: Finished systemd-machine-id-commit.service - Commit a transient machine-id on disk. Oct 8 19:56:22.625849 systemd[1]: Starting systemd-sysusers.service - Create System Users... Oct 8 19:56:22.629664 kernel: loop1: detected capacity change from 0 to 140768 Oct 8 19:56:22.666685 kernel: loop2: detected capacity change from 0 to 142488 Oct 8 19:56:22.670116 systemd[1]: Finished systemd-sysusers.service - Create System Users. Oct 8 19:56:22.683670 kernel: loop3: detected capacity change from 0 to 140768 Oct 8 19:56:22.680987 systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev... Oct 8 19:56:22.694099 (sd-merge)[1193]: Using extensions 'containerd-flatcar', 'docker-flatcar'. Oct 8 19:56:22.694734 (sd-merge)[1193]: Merged extensions into '/usr'. Oct 8 19:56:22.698024 systemd[1]: Finished systemd-sysext.service - Merge System Extension Images into /usr/ and /opt/. Oct 8 19:56:22.706383 systemd[1]: Starting ensure-sysext.service... Oct 8 19:56:22.706486 systemd-tmpfiles[1195]: ACLs are not supported, ignoring. Oct 8 19:56:22.706504 systemd-tmpfiles[1195]: ACLs are not supported, ignoring. Oct 8 19:56:22.712793 systemd[1]: Starting systemd-tmpfiles-setup.service - Create System Files and Directories... Oct 8 19:56:22.714548 systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev. Oct 8 19:56:22.722782 systemd[1]: Reloading requested from client PID 1198 ('systemctl') (unit ensure-sysext.service)... Oct 8 19:56:22.722800 systemd[1]: Reloading... Oct 8 19:56:22.739991 systemd-tmpfiles[1199]: /usr/lib/tmpfiles.d/provision.conf:20: Duplicate line for path "/root", ignoring. Oct 8 19:56:22.740312 systemd-tmpfiles[1199]: /usr/lib/tmpfiles.d/systemd-flatcar.conf:6: Duplicate line for path "/var/log/journal", ignoring. Oct 8 19:56:22.741306 systemd-tmpfiles[1199]: /usr/lib/tmpfiles.d/systemd.conf:29: Duplicate line for path "/var/lib/systemd", ignoring. Oct 8 19:56:22.741607 systemd-tmpfiles[1199]: ACLs are not supported, ignoring. Oct 8 19:56:22.741732 systemd-tmpfiles[1199]: ACLs are not supported, ignoring. Oct 8 19:56:22.745437 systemd-tmpfiles[1199]: Detected autofs mount point /boot during canonicalization of boot. Oct 8 19:56:22.745675 systemd-tmpfiles[1199]: Skipping /boot Oct 8 19:56:22.758105 systemd-tmpfiles[1199]: Detected autofs mount point /boot during canonicalization of boot. Oct 8 19:56:22.758274 systemd-tmpfiles[1199]: Skipping /boot Oct 8 19:56:22.797691 zram_generator::config[1227]: No configuration found. Oct 8 19:56:22.893981 ldconfig[1165]: /sbin/ldconfig: /lib/ld.so.conf is not an ELF file - it has the wrong magic bytes at the start. Oct 8 19:56:22.926471 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. Oct 8 19:56:22.978231 systemd[1]: Reloading finished in 254 ms. Oct 8 19:56:23.012579 systemd[1]: Finished ldconfig.service - Rebuild Dynamic Linker Cache. Oct 8 19:56:23.023295 systemd[1]: Finished systemd-tmpfiles-setup.service - Create System Files and Directories. Oct 8 19:56:23.031823 systemd[1]: Starting audit-rules.service - Load Security Auditing Rules... Oct 8 19:56:23.034572 systemd[1]: Starting clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs... Oct 8 19:56:23.039821 systemd[1]: Starting systemd-journal-catalog-update.service - Rebuild Journal Catalog... Oct 8 19:56:23.048566 systemd[1]: Starting systemd-resolved.service - Network Name Resolution... Oct 8 19:56:23.052938 systemd[1]: Starting systemd-update-utmp.service - Record System Boot/Shutdown in UTMP... Oct 8 19:56:23.060392 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:23.060707 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:56:23.063097 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:56:23.068731 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:56:23.073771 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:56:23.075165 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:56:23.081993 systemd[1]: Starting systemd-userdbd.service - User Database Manager... Oct 8 19:56:23.083704 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:23.085419 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:56:23.085932 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:56:23.089299 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:56:23.089733 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:56:23.094149 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:56:23.094496 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:56:23.099259 systemd[1]: Finished systemd-journal-catalog-update.service - Rebuild Journal Catalog. Oct 8 19:56:23.113949 systemd[1]: Finished systemd-update-utmp.service - Record System Boot/Shutdown in UTMP. Oct 8 19:56:23.119730 systemd[1]: proc-xen.mount - /proc/xen was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:23.120059 systemd[1]: ignition-delete-config.service - Ignition (delete config) was skipped because no trigger condition checks were met. Oct 8 19:56:23.129211 systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod... Oct 8 19:56:23.133624 systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm... Oct 8 19:56:23.137837 systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... Oct 8 19:56:23.139730 augenrules[1297]: No rules Oct 8 19:56:23.142028 systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop... Oct 8 19:56:23.143428 systemd[1]: systemd-binfmt.service - Set Up Additional Binary Formats was skipped because no trigger condition checks were met. Oct 8 19:56:23.143617 systemd[1]: xenserver-pv-version.service - Set fake PV driver version for XenServer was skipped because of an unmet condition check (ConditionVirtualization=xen). Oct 8 19:56:23.144795 systemd[1]: Finished audit-rules.service - Load Security Auditing Rules. Oct 8 19:56:23.146667 systemd[1]: modprobe@dm_mod.service: Deactivated successfully. Oct 8 19:56:23.146880 systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod. Oct 8 19:56:23.147607 systemd[1]: modprobe@efi_pstore.service: Deactivated successfully. Oct 8 19:56:23.147819 systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore. Oct 8 19:56:23.151276 systemd[1]: modprobe@drm.service: Deactivated successfully. Oct 8 19:56:23.151492 systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm. Oct 8 19:56:23.153297 systemd[1]: modprobe@loop.service: Deactivated successfully. Oct 8 19:56:23.153483 systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop. Oct 8 19:56:23.157404 systemd[1]: Finished ensure-sysext.service. Oct 8 19:56:23.164014 systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore). Oct 8 19:56:23.164122 systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met. Oct 8 19:56:23.175048 systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization... Oct 8 19:56:23.180034 systemd[1]: Finished clean-ca-certificates.service - Clean up broken links in /etc/ssl/certs. Oct 8 19:56:23.181803 systemd[1]: Started systemd-userdbd.service - User Database Manager. Oct 8 19:56:23.184189 systemd[1]: update-ca-certificates.service - Update CA bundle at /etc/ssl/certs/ca-certificates.crt was skipped because of an unmet condition check (ConditionPathIsSymbolicLink=!/etc/ssl/certs/ca-certificates.crt). Oct 8 19:56:23.233063 systemd[1]: Finished systemd-hwdb-update.service - Rebuild Hardware Database. Oct 8 19:56:23.247053 systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files... Oct 8 19:56:23.251918 systemd[1]: Starting systemd-update-done.service - Update is Completed... Oct 8 19:56:23.258145 systemd-resolved[1271]: Positive Trust Anchors: Oct 8 19:56:23.258170 systemd-resolved[1271]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Oct 8 19:56:23.258203 systemd-resolved[1271]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test Oct 8 19:56:23.262285 systemd-resolved[1271]: Defaulting to hostname 'linux'. Oct 8 19:56:23.263294 systemd[1]: Started systemd-timesyncd.service - Network Time Synchronization. Oct 8 19:56:23.264985 systemd[1]: Started systemd-resolved.service - Network Name Resolution. Oct 8 19:56:23.266505 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups. Oct 8 19:56:23.267961 systemd[1]: Reached target time-set.target - System Time Set. Oct 8 19:56:23.269490 systemd[1]: Finished systemd-update-done.service - Update is Completed. Oct 8 19:56:23.292217 systemd-udevd[1320]: Using default interface naming scheme 'v255'. Oct 8 19:56:23.315102 systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files. Oct 8 19:56:23.325873 systemd[1]: Starting systemd-networkd.service - Network Configuration... Oct 8 19:56:23.352962 systemd[1]: Condition check resulted in dev-ttyS0.device - /dev/ttyS0 being skipped. Oct 8 19:56:23.366710 kernel: BTRFS info: devid 1 device path /dev/mapper/usr changed to /dev/dm-0 scanned by (udev-worker) (1333) Oct 8 19:56:23.372658 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1332) Oct 8 19:56:23.381725 kernel: BTRFS info: devid 1 device path /dev/dm-0 changed to /dev/mapper/usr scanned by (udev-worker) (1333) Oct 8 19:56:23.397408 systemd-networkd[1327]: lo: Link UP Oct 8 19:56:23.397430 systemd-networkd[1327]: lo: Gained carrier Oct 8 19:56:23.399172 systemd-networkd[1327]: Enumeration completed Oct 8 19:56:23.401557 systemd[1]: Found device dev-disk-by\x2dlabel-OEM.device - /dev/disk/by-label/OEM. Oct 8 19:56:23.404032 systemd[1]: Started systemd-networkd.service - Network Configuration. Oct 8 19:56:23.412490 systemd[1]: Reached target network.target - Network. Oct 8 19:56:23.422915 systemd[1]: Starting systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM... Oct 8 19:56:23.428583 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input2 Oct 8 19:56:23.427711 systemd[1]: Starting systemd-networkd-wait-online.service - Wait for Network to be Configured... Oct 8 19:56:23.427712 systemd-networkd[1327]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:56:23.427718 systemd-networkd[1327]: eth0: Configuring with /usr/lib/systemd/network/zz-default.network. Oct 8 19:56:23.430943 systemd-networkd[1327]: eth0: Link UP Oct 8 19:56:23.430955 systemd-networkd[1327]: eth0: Gained carrier Oct 8 19:56:23.430974 systemd-networkd[1327]: eth0: found matching network '/usr/lib/systemd/network/zz-default.network', based on potentially unpredictable interface name. Oct 8 19:56:23.437660 kernel: ACPI: button: Power Button [PWRF] Oct 8 19:56:23.438773 systemd[1]: Finished systemd-fsck@dev-disk-by\x2dlabel-OEM.service - File System Check on /dev/disk/by-label/OEM. Oct 8 19:56:23.444872 systemd-networkd[1327]: eth0: DHCPv4 address 10.0.0.64/16, gateway 10.0.0.1 acquired from 10.0.0.1 Oct 8 19:56:23.446487 systemd-timesyncd[1311]: Network configuration changed, trying to establish connection. Oct 8 19:56:24.237068 systemd-resolved[1271]: Clock change detected. Flushing caches. Oct 8 19:56:24.237153 systemd-timesyncd[1311]: Contacted time server 10.0.0.1:123 (10.0.0.1). Oct 8 19:56:24.237215 systemd-timesyncd[1311]: Initial clock synchronization to Tue 2024-10-08 19:56:24.237006 UTC. Oct 8 19:56:24.256590 kernel: input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3 Oct 8 19:56:24.275263 kernel: i801_smbus 0000:00:1f.3: Enabling SMBus device Oct 8 19:56:24.277659 kernel: i801_smbus 0000:00:1f.3: SMBus using PCI interrupt Oct 8 19:56:24.277854 kernel: i2c i2c-0: 1/1 memory slots populated (from DMI) Oct 8 19:56:24.278054 kernel: i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD Oct 8 19:56:24.302918 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:56:24.314221 systemd[1]: systemd-vconsole-setup.service: Deactivated successfully. Oct 8 19:56:24.314660 systemd[1]: Stopped systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:24.322855 systemd[1]: Starting systemd-vconsole-setup.service - Virtual Console Setup... Oct 8 19:56:24.358817 kernel: mousedev: PS/2 mouse device common for all mice Oct 8 19:56:24.372846 kernel: kvm_amd: TSC scaling supported Oct 8 19:56:24.372956 kernel: kvm_amd: Nested Virtualization enabled Oct 8 19:56:24.372980 kernel: kvm_amd: Nested Paging enabled Oct 8 19:56:24.372993 kernel: kvm_amd: LBR virtualization supported Oct 8 19:56:24.374045 kernel: kvm_amd: Virtual VMLOAD VMSAVE supported Oct 8 19:56:24.374064 kernel: kvm_amd: Virtual GIF supported Oct 8 19:56:24.398603 kernel: EDAC MC: Ver: 3.0.0 Oct 8 19:56:24.408658 systemd[1]: Finished systemd-vconsole-setup.service - Virtual Console Setup. Oct 8 19:56:24.430207 systemd[1]: Finished systemd-udev-settle.service - Wait for udev To Complete Device Initialization. Oct 8 19:56:24.442868 systemd[1]: Starting lvm2-activation-early.service - Activation of LVM2 logical volumes... Oct 8 19:56:24.453105 lvm[1371]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Oct 8 19:56:24.495134 systemd[1]: Finished lvm2-activation-early.service - Activation of LVM2 logical volumes. Oct 8 19:56:24.497004 systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes. Oct 8 19:56:24.498314 systemd[1]: Reached target sysinit.target - System Initialization. Oct 8 19:56:24.499713 systemd[1]: Started motdgen.path - Watch for update engine configuration changes. Oct 8 19:56:24.501234 systemd[1]: Started user-cloudinit@var-lib-flatcar\x2dinstall-user_data.path - Watch for a cloud-config at /var/lib/flatcar-install/user_data. Oct 8 19:56:24.502974 systemd[1]: Started logrotate.timer - Daily rotation of log files. Oct 8 19:56:24.504421 systemd[1]: Started mdadm.timer - Weekly check for MD array's redundancy information.. Oct 8 19:56:24.505927 systemd[1]: Started systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Oct 8 19:56:24.507428 systemd[1]: update-engine-stub.timer - Update Engine Stub Timer was skipped because of an unmet condition check (ConditionPathExists=/usr/.noupdate). Oct 8 19:56:24.507463 systemd[1]: Reached target paths.target - Path Units. Oct 8 19:56:24.508524 systemd[1]: Reached target timers.target - Timer Units. Oct 8 19:56:24.510428 systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket. Oct 8 19:56:24.513699 systemd[1]: Starting docker.socket - Docker Socket for the API... Oct 8 19:56:24.523074 systemd[1]: Listening on sshd.socket - OpenSSH Server Socket. Oct 8 19:56:24.526490 systemd[1]: Starting lvm2-activation.service - Activation of LVM2 logical volumes... Oct 8 19:56:24.528477 systemd[1]: Listening on docker.socket - Docker Socket for the API. Oct 8 19:56:24.529871 systemd[1]: Reached target sockets.target - Socket Units. Oct 8 19:56:24.531048 systemd[1]: Reached target basic.target - Basic System. Oct 8 19:56:24.532235 systemd[1]: addon-config@oem.service - Configure Addon /oem was skipped because no trigger condition checks were met. Oct 8 19:56:24.532270 systemd[1]: addon-run@oem.service - Run Addon /oem was skipped because no trigger condition checks were met. Oct 8 19:56:24.533839 systemd[1]: Starting containerd.service - containerd container runtime... Oct 8 19:56:24.536627 systemd[1]: Starting dbus.service - D-Bus System Message Bus... Oct 8 19:56:24.540281 lvm[1375]: WARNING: Failed to connect to lvmetad. Falling back to device scanning. Oct 8 19:56:24.541720 systemd[1]: Starting enable-oem-cloudinit.service - Enable cloudinit... Oct 8 19:56:24.547444 systemd[1]: Starting extend-filesystems.service - Extend Filesystems... Oct 8 19:56:24.548787 systemd[1]: flatcar-setup-environment.service - Modifies /etc/environment for CoreOS was skipped because of an unmet condition check (ConditionPathExists=/oem/bin/flatcar-setup-environment). Oct 8 19:56:24.552726 systemd[1]: Starting motdgen.service - Generate /run/flatcar/motd... Oct 8 19:56:24.555116 jq[1378]: false Oct 8 19:56:24.555174 systemd[1]: Starting ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline... Oct 8 19:56:24.558823 systemd[1]: Starting sshd-keygen.service - Generate sshd host keys... Oct 8 19:56:24.564712 systemd[1]: Starting systemd-logind.service - User Login Management... Oct 8 19:56:24.567495 systemd[1]: tcsd.service - TCG Core Services Daemon was skipped because of an unmet condition check (ConditionPathExists=/dev/tpm0). Oct 8 19:56:24.567965 systemd[1]: cgroup compatibility translation between legacy and unified hierarchy settings activated. See cgroup-compat debug messages for details. Oct 8 19:56:24.568732 systemd[1]: Starting update-engine.service - Update Engine... Oct 8 19:56:24.571659 systemd[1]: Starting update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition... Oct 8 19:56:24.575176 systemd[1]: Finished lvm2-activation.service - Activation of LVM2 logical volumes. Oct 8 19:56:24.577836 systemd[1]: enable-oem-cloudinit.service: Skipped due to 'exec-condition'. Oct 8 19:56:24.578110 systemd[1]: Condition check resulted in enable-oem-cloudinit.service - Enable cloudinit being skipped. Oct 8 19:56:24.594669 jq[1387]: true Oct 8 19:56:24.596012 systemd[1]: ssh-key-proc-cmdline.service: Deactivated successfully. Oct 8 19:56:24.596362 systemd[1]: Finished ssh-key-proc-cmdline.service - Install an ssh key from /proc/cmdline. Oct 8 19:56:24.608043 extend-filesystems[1379]: Found loop2 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found loop3 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found sr0 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda1 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda2 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda3 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found usr Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda4 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda6 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda7 Oct 8 19:56:24.608043 extend-filesystems[1379]: Found vda9 Oct 8 19:56:24.608043 extend-filesystems[1379]: Checking size of /dev/vda9 Oct 8 19:56:24.665645 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1333) Oct 8 19:56:24.665677 update_engine[1386]: I20241008 19:56:24.606647 1386 main.cc:92] Flatcar Update Engine starting Oct 8 19:56:24.665677 update_engine[1386]: I20241008 19:56:24.610507 1386 update_check_scheduler.cc:74] Next update check in 4m26s Oct 8 19:56:24.604535 dbus-daemon[1377]: [system] SELinux support is enabled Oct 8 19:56:24.615715 systemd[1]: Started dbus.service - D-Bus System Message Bus. Oct 8 19:56:24.666526 extend-filesystems[1379]: Old size kept for /dev/vda9 Oct 8 19:56:24.615965 (ntainerd)[1398]: containerd.service: Referenced but unset environment variable evaluates to an empty string: TORCX_IMAGEDIR, TORCX_UNPACKDIR Oct 8 19:56:24.669749 jq[1399]: true Oct 8 19:56:24.619500 systemd[1]: motdgen.service: Deactivated successfully. Oct 8 19:56:24.620420 systemd[1]: Finished motdgen.service - Generate /run/flatcar/motd. Oct 8 19:56:24.625050 systemd[1]: system-cloudinit@usr-share-oem-cloud\x2dconfig.yml.service - Load cloud-config from /usr/share/oem/cloud-config.yml was skipped because of an unmet condition check (ConditionFileNotEmpty=/usr/share/oem/cloud-config.yml). Oct 8 19:56:24.625114 systemd[1]: Reached target system-config.target - Load system-provided cloud configs. Oct 8 19:56:24.626811 systemd[1]: user-cloudinit-proc-cmdline.service - Load cloud-config from url defined in /proc/cmdline was skipped because of an unmet condition check (ConditionKernelCommandLine=cloud-config-url). Oct 8 19:56:24.626834 systemd[1]: Reached target user-config.target - Load user-provided cloud configs. Oct 8 19:56:24.630539 systemd[1]: Started update-engine.service - Update Engine. Oct 8 19:56:24.654805 systemd[1]: Started locksmithd.service - Cluster reboot manager. Oct 8 19:56:24.656798 systemd[1]: extend-filesystems.service: Deactivated successfully. Oct 8 19:56:24.657294 systemd[1]: Finished extend-filesystems.service - Extend Filesystems. Oct 8 19:56:24.712051 systemd-logind[1384]: Watching system buttons on /dev/input/event1 (Power Button) Oct 8 19:56:24.712093 systemd-logind[1384]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard) Oct 8 19:56:24.713325 systemd-logind[1384]: New seat seat0. Oct 8 19:56:24.714181 sshd_keygen[1403]: ssh-keygen: generating new host keys: RSA ECDSA ED25519 Oct 8 19:56:24.714770 systemd[1]: Started systemd-logind.service - User Login Management. Oct 8 19:56:24.728228 locksmithd[1410]: locksmithd starting currentOperation="UPDATE_STATUS_IDLE" strategy="reboot" Oct 8 19:56:24.736345 bash[1436]: Updated "/home/core/.ssh/authorized_keys" Oct 8 19:56:24.737594 systemd[1]: Finished update-ssh-keys-after-ignition.service - Run update-ssh-keys once after Ignition. Oct 8 19:56:24.741863 systemd[1]: sshkeys.service was skipped because no trigger condition checks were met. Oct 8 19:56:24.745285 systemd[1]: Finished sshd-keygen.service - Generate sshd host keys. Oct 8 19:56:24.755963 systemd[1]: Starting issuegen.service - Generate /run/issue... Oct 8 19:56:24.764547 systemd[1]: issuegen.service: Deactivated successfully. Oct 8 19:56:24.764898 systemd[1]: Finished issuegen.service - Generate /run/issue. Oct 8 19:56:24.784062 systemd[1]: Starting systemd-user-sessions.service - Permit User Sessions... Oct 8 19:56:24.796523 systemd[1]: Finished systemd-user-sessions.service - Permit User Sessions. Oct 8 19:56:24.808267 systemd[1]: Started getty@tty1.service - Getty on tty1. Oct 8 19:56:24.811663 systemd[1]: Started serial-getty@ttyS0.service - Serial Getty on ttyS0. Oct 8 19:56:24.813191 systemd[1]: Reached target getty.target - Login Prompts. Oct 8 19:56:24.873554 containerd[1398]: time="2024-10-08T19:56:24.873429379Z" level=info msg="starting containerd" revision=174e0d1785eeda18dc2beba45e1d5a188771636b version=v1.7.21 Oct 8 19:56:25.062471 containerd[1398]: time="2024-10-08T19:56:25.062200893Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.aufs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.064831 containerd[1398]: time="2024-10-08T19:56:25.064749293Z" 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.54-flatcar\\n\"): skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:56:25.064831 containerd[1398]: time="2024-10-08T19:56:25.064805187Z" level=info msg="loading plugin \"io.containerd.event.v1.exchange\"..." type=io.containerd.event.v1 Oct 8 19:56:25.064831 containerd[1398]: time="2024-10-08T19:56:25.064827970Z" level=info msg="loading plugin \"io.containerd.internal.v1.opt\"..." type=io.containerd.internal.v1 Oct 8 19:56:25.065156 containerd[1398]: time="2024-10-08T19:56:25.065123394Z" level=info msg="loading plugin \"io.containerd.warning.v1.deprecations\"..." type=io.containerd.warning.v1 Oct 8 19:56:25.065186 containerd[1398]: time="2024-10-08T19:56:25.065157107Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065272 containerd[1398]: time="2024-10-08T19:56:25.065240263Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.blockfile\"..." error="no scratch file generator: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065272 containerd[1398]: time="2024-10-08T19:56:25.065258708Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.btrfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065612 containerd[1398]: time="2024-10-08T19:56:25.065576744Z" 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 Oct 8 19:56:25.065612 containerd[1398]: time="2024-10-08T19:56:25.065598425Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065675 containerd[1398]: time="2024-10-08T19:56:25.065613183Z" level=info msg="skip loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." error="devmapper not configured: skip plugin" type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065675 containerd[1398]: time="2024-10-08T19:56:25.065623692Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.065807 containerd[1398]: time="2024-10-08T19:56:25.065747424Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.066089 containerd[1398]: time="2024-10-08T19:56:25.066058458Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.zfs\"..." type=io.containerd.snapshotter.v1 Oct 8 19:56:25.066245 containerd[1398]: time="2024-10-08T19:56:25.066218548Z" 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 Oct 8 19:56:25.066245 containerd[1398]: time="2024-10-08T19:56:25.066235880Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1 Oct 8 19:56:25.066371 containerd[1398]: time="2024-10-08T19:56:25.066347931Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1 Oct 8 19:56:25.066446 containerd[1398]: time="2024-10-08T19:56:25.066426668Z" level=info msg="metadata content store policy set" policy=shared Oct 8 19:56:25.269438 containerd[1398]: time="2024-10-08T19:56:25.269325245Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1 Oct 8 19:56:25.270184 containerd[1398]: time="2024-10-08T19:56:25.269704958Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1 Oct 8 19:56:25.270184 containerd[1398]: time="2024-10-08T19:56:25.269857874Z" level=info msg="loading plugin \"io.containerd.lease.v1.manager\"..." type=io.containerd.lease.v1 Oct 8 19:56:25.270184 containerd[1398]: time="2024-10-08T19:56:25.269894243Z" level=info msg="loading plugin \"io.containerd.streaming.v1.manager\"..." type=io.containerd.streaming.v1 Oct 8 19:56:25.270184 containerd[1398]: time="2024-10-08T19:56:25.269925451Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." type=io.containerd.runtime.v1 Oct 8 19:56:25.270357 containerd[1398]: time="2024-10-08T19:56:25.270274796Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." type=io.containerd.monitor.v1 Oct 8 19:56:25.270828 containerd[1398]: time="2024-10-08T19:56:25.270792487Z" level=info msg="loading plugin \"io.containerd.runtime.v2.task\"..." type=io.containerd.runtime.v2 Oct 8 19:56:25.271090 containerd[1398]: time="2024-10-08T19:56:25.271057554Z" level=info msg="loading plugin \"io.containerd.runtime.v2.shim\"..." type=io.containerd.runtime.v2 Oct 8 19:56:25.271090 containerd[1398]: time="2024-10-08T19:56:25.271081950Z" level=info msg="loading plugin \"io.containerd.sandbox.store.v1.local\"..." type=io.containerd.sandbox.store.v1 Oct 8 19:56:25.271145 containerd[1398]: time="2024-10-08T19:56:25.271095646Z" level=info msg="loading plugin \"io.containerd.sandbox.controller.v1.local\"..." type=io.containerd.sandbox.controller.v1 Oct 8 19:56:25.271145 containerd[1398]: time="2024-10-08T19:56:25.271109932Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271145 containerd[1398]: time="2024-10-08T19:56:25.271122296Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271145 containerd[1398]: time="2024-10-08T19:56:25.271134198Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271149957Z" level=info msg="loading plugin \"io.containerd.service.v1.images-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271166629Z" level=info msg="loading plugin \"io.containerd.service.v1.introspection-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271179333Z" level=info msg="loading plugin \"io.containerd.service.v1.namespaces-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271191365Z" level=info msg="loading plugin \"io.containerd.service.v1.snapshots-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271203217Z" level=info msg="loading plugin \"io.containerd.service.v1.tasks-service\"..." type=io.containerd.service.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271224197Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271238403Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271257519Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271271666Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271287065Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271299 containerd[1398]: time="2024-10-08T19:56:25.271301742Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271320097Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271334634Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271348019Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandbox-controllers\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271362596Z" level=info msg="loading plugin \"io.containerd.grpc.v1.sandboxes\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271374979Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271387553Z" level=info msg="loading plugin \"io.containerd.grpc.v1.streaming\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271400768Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271425665Z" level=info msg="loading plugin \"io.containerd.transfer.v1.local\"..." type=io.containerd.transfer.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271451042Z" level=info msg="loading plugin \"io.containerd.grpc.v1.transfer\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271465740Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271476410Z" level=info msg="loading plugin \"io.containerd.internal.v1.restart\"..." type=io.containerd.internal.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271529710Z" level=info msg="loading plugin \"io.containerd.tracing.processor.v1.otlp\"..." type=io.containerd.tracing.processor.v1 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271551881Z" 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 Oct 8 19:56:25.271586 containerd[1398]: time="2024-10-08T19:56:25.271582699Z" level=info msg="loading plugin \"io.containerd.internal.v1.tracing\"..." type=io.containerd.internal.v1 Oct 8 19:56:25.271930 containerd[1398]: time="2024-10-08T19:56:25.271594591Z" level=info msg="skip loading plugin \"io.containerd.internal.v1.tracing\"..." error="skip plugin: tracing endpoint not configured" type=io.containerd.internal.v1 Oct 8 19:56:25.271930 containerd[1398]: time="2024-10-08T19:56:25.271604690Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.271930 containerd[1398]: time="2024-10-08T19:56:25.271617594Z" level=info msg="loading plugin \"io.containerd.nri.v1.nri\"..." type=io.containerd.nri.v1 Oct 8 19:56:25.271930 containerd[1398]: time="2024-10-08T19:56:25.271628355Z" level=info msg="NRI interface is disabled by configuration." Oct 8 19:56:25.271930 containerd[1398]: time="2024-10-08T19:56:25.271638804Z" level=info msg="loading plugin \"io.containerd.grpc.v1.cri\"..." type=io.containerd.grpc.v1 Oct 8 19:56:25.272064 containerd[1398]: time="2024-10-08T19:56:25.271930391Z" 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}" Oct 8 19:56:25.272064 containerd[1398]: time="2024-10-08T19:56:25.271983791Z" level=info msg="Connect containerd service" Oct 8 19:56:25.272064 containerd[1398]: time="2024-10-08T19:56:25.272026601Z" level=info msg="using legacy CRI server" Oct 8 19:56:25.272064 containerd[1398]: time="2024-10-08T19:56:25.272035188Z" level=info msg="using experimental NRI integration - disable nri plugin to prevent this" Oct 8 19:56:25.272325 containerd[1398]: time="2024-10-08T19:56:25.272140134Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\"" Oct 8 19:56:25.272851 containerd[1398]: time="2024-10-08T19:56:25.272813888Z" level=error msg="failed to load cni during init, please check CRI plugin status before setting up network for pods" error="cni config load failed: no network config found in /etc/cni/net.d: cni plugin not initialized: failed to load cni config" Oct 8 19:56:25.273040 containerd[1398]: time="2024-10-08T19:56:25.272982725Z" level=info msg="Start subscribing containerd event" Oct 8 19:56:25.273090 containerd[1398]: time="2024-10-08T19:56:25.273066061Z" level=info msg="Start recovering state" Oct 8 19:56:25.273297 containerd[1398]: time="2024-10-08T19:56:25.273273780Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc Oct 8 19:56:25.273297 containerd[1398]: time="2024-10-08T19:56:25.273283619Z" level=info msg="Start event monitor" Oct 8 19:56:25.273385 containerd[1398]: time="2024-10-08T19:56:25.273314617Z" level=info msg="Start snapshots syncer" Oct 8 19:56:25.273385 containerd[1398]: time="2024-10-08T19:56:25.273337380Z" level=info msg=serving... address=/run/containerd/containerd.sock Oct 8 19:56:25.273385 containerd[1398]: time="2024-10-08T19:56:25.273339594Z" level=info msg="Start cni network conf syncer for default" Oct 8 19:56:25.273385 containerd[1398]: time="2024-10-08T19:56:25.273378437Z" level=info msg="Start streaming server" Oct 8 19:56:25.273540 containerd[1398]: time="2024-10-08T19:56:25.273517888Z" level=info msg="containerd successfully booted in 0.402547s" Oct 8 19:56:25.273644 systemd[1]: Started containerd.service - containerd container runtime. Oct 8 19:56:25.942855 systemd-networkd[1327]: eth0: Gained IPv6LL Oct 8 19:56:25.946609 systemd[1]: Finished systemd-networkd-wait-online.service - Wait for Network to be Configured. Oct 8 19:56:25.966223 systemd[1]: Reached target network-online.target - Network is Online. Oct 8 19:56:25.982863 systemd[1]: Starting coreos-metadata.service - QEMU metadata agent... Oct 8 19:56:25.985289 systemd[1]: Starting nvidia.service - NVIDIA Configure Service... Oct 8 19:56:26.007206 systemd[1]: coreos-metadata.service: Deactivated successfully. Oct 8 19:56:26.007479 systemd[1]: Finished coreos-metadata.service - QEMU metadata agent. Oct 8 19:56:26.138277 systemd[1]: Finished nvidia.service - NVIDIA Configure Service. Oct 8 19:56:26.156164 systemd[1]: Starting etcd-member.service - etcd (System Application Container)... Oct 8 19:56:26.156449 (-wrapper)[1475]: etcd-member.service: Referenced but unset environment variable evaluates to an empty string: ETCD_OPTS Oct 8 19:56:26.157494 systemd[1]: packet-phone-home.service - Report Success to Packet was skipped because no trigger condition checks were met. Oct 8 19:56:26.278966 systemd[1]: Starting docker.service - Docker Application Container Engine... Oct 8 19:56:26.279157 (dockerd)[1485]: docker.service: Referenced but unset environment variable evaluates to an empty string: DOCKER_CGROUPS, DOCKER_OPTS, DOCKER_OPT_BIP, DOCKER_OPT_IPMASQ, DOCKER_OPT_MTU Oct 8 19:56:26.563112 dockerd[1485]: time="2024-10-08T19:56:26.562975431Z" level=info msg="Starting up" Oct 8 19:56:27.584655 dockerd[1485]: time="2024-10-08T19:56:27.584587689Z" level=info msg="Loading containers: start." Oct 8 19:56:28.144598 kernel: Initializing XFRM netlink socket Oct 8 19:56:28.225143 systemd-networkd[1327]: docker0: Link UP Oct 8 19:56:28.433852 dockerd[1485]: time="2024-10-08T19:56:28.433716438Z" level=info msg="Loading containers: done." Oct 8 19:56:28.451283 systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck3438255822-merged.mount: Deactivated successfully. Oct 8 19:56:28.452947 dockerd[1485]: time="2024-10-08T19:56:28.452874086Z" level=warning msg="Not using native diff for overlay2, this may cause degraded performance for building images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled" storage-driver=overlay2 Oct 8 19:56:28.453059 dockerd[1485]: time="2024-10-08T19:56:28.453019418Z" level=info msg="Docker daemon" commit=061aa95809be396a6b5542618d8a34b02a21ff77 containerd-snapshotter=false storage-driver=overlay2 version=26.1.0 Oct 8 19:56:28.453217 dockerd[1485]: time="2024-10-08T19:56:28.453187404Z" level=info msg="Daemon has completed initialization" Oct 8 19:56:28.611122 dockerd[1485]: time="2024-10-08T19:56:28.611028422Z" level=info msg="API listen on /run/docker.sock" Oct 8 19:56:28.611804 systemd[1]: Started docker.service - Docker Application Container Engine. Oct 8 19:56:28.614579 etcd-wrapper[1479]: Error response from daemon: No such container: etcd-member Oct 8 19:56:28.630984 etcd-wrapper[1615]: Error response from daemon: No such container: etcd-member Oct 8 19:56:28.666938 etcd-wrapper[1634]: Unable to find image 'quay.io/coreos/etcd:v3.5.16' locally Oct 8 19:56:30.007168 etcd-wrapper[1634]: v3.5.16: Pulling from coreos/etcd Oct 8 19:56:30.236338 etcd-wrapper[1634]: 804c8aba2cc6: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: 2ae710cd8bfe: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: d462aa345367: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: 0f8b424aa0b9: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: d557676654e5: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: c8022d07192e: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: d858cbc252ad: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: 1069fc2daed1: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: b40161cd83fc: Pulling fs layer Oct 8 19:56:30.236338 etcd-wrapper[1634]: 5318d93a3a65: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: 307c1adadb60: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: fbb01d9e9dc9: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: fbfea02ac3cf: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: 8c26e4bf18e2: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: 1e59a65f8816: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: ffbd4ca5f0bd: Pulling fs layer Oct 8 19:56:30.236812 etcd-wrapper[1634]: 0f8b424aa0b9: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: d557676654e5: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: c8022d07192e: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: d858cbc252ad: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: 1069fc2daed1: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: b40161cd83fc: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: 5318d93a3a65: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: 307c1adadb60: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: fbb01d9e9dc9: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: fbfea02ac3cf: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: 8c26e4bf18e2: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: 1e59a65f8816: Waiting Oct 8 19:56:30.236812 etcd-wrapper[1634]: ffbd4ca5f0bd: Waiting Oct 8 19:56:30.501305 etcd-wrapper[1634]: d462aa345367: Verifying Checksum Oct 8 19:56:30.501305 etcd-wrapper[1634]: d462aa345367: Download complete Oct 8 19:56:30.502576 etcd-wrapper[1634]: 804c8aba2cc6: Download complete Oct 8 19:56:30.623717 etcd-wrapper[1634]: 2ae710cd8bfe: Verifying Checksum Oct 8 19:56:30.623717 etcd-wrapper[1634]: 2ae710cd8bfe: Download complete Oct 8 19:56:30.750975 etcd-wrapper[1634]: d557676654e5: Verifying Checksum Oct 8 19:56:30.750975 etcd-wrapper[1634]: d557676654e5: Download complete Oct 8 19:56:30.801783 etcd-wrapper[1634]: 0f8b424aa0b9: Verifying Checksum Oct 8 19:56:30.801783 etcd-wrapper[1634]: 0f8b424aa0b9: Download complete Oct 8 19:56:30.886902 etcd-wrapper[1634]: 804c8aba2cc6: Pull complete Oct 8 19:56:30.972316 etcd-wrapper[1634]: c8022d07192e: Verifying Checksum Oct 8 19:56:30.972316 etcd-wrapper[1634]: c8022d07192e: Download complete Oct 8 19:56:30.984991 systemd[1]: var-lib-docker-overlay2-99e656436429ad45946e6c1413b9a0e4db1fa0d61df9327727aecfc735ab8b93-merged.mount: Deactivated successfully. Oct 8 19:56:31.013711 etcd-wrapper[1634]: d858cbc252ad: Verifying Checksum Oct 8 19:56:31.013711 etcd-wrapper[1634]: d858cbc252ad: Download complete Oct 8 19:56:31.040839 etcd-wrapper[1634]: 1069fc2daed1: Verifying Checksum Oct 8 19:56:31.040839 etcd-wrapper[1634]: 1069fc2daed1: Download complete Oct 8 19:56:31.152401 etcd-wrapper[1634]: 2ae710cd8bfe: Pull complete Oct 8 19:56:31.208769 etcd-wrapper[1634]: b40161cd83fc: Verifying Checksum Oct 8 19:56:31.208769 etcd-wrapper[1634]: b40161cd83fc: Download complete Oct 8 19:56:31.259596 etcd-wrapper[1634]: 5318d93a3a65: Verifying Checksum Oct 8 19:56:31.259596 etcd-wrapper[1634]: 5318d93a3a65: Download complete Oct 8 19:56:31.277137 etcd-wrapper[1634]: 307c1adadb60: Verifying Checksum Oct 8 19:56:31.277137 etcd-wrapper[1634]: 307c1adadb60: Download complete Oct 8 19:56:31.499196 systemd[1]: Created slice system-sshd.slice - Slice /system/sshd. Oct 8 19:56:31.510327 systemd[1]: Started sshd@0-10.0.0.64:22-10.0.0.1:57094.service - OpenSSH per-connection server daemon (10.0.0.1:57094). Oct 8 19:56:31.523925 etcd-wrapper[1634]: fbb01d9e9dc9: Verifying Checksum Oct 8 19:56:31.523925 etcd-wrapper[1634]: fbb01d9e9dc9: Download complete Oct 8 19:56:31.559798 etcd-wrapper[1634]: fbfea02ac3cf: Verifying Checksum Oct 8 19:56:31.559798 etcd-wrapper[1634]: fbfea02ac3cf: Download complete Oct 8 19:56:31.573887 sshd[1666]: Accepted publickey for core from 10.0.0.1 port 57094 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:31.576603 sshd[1666]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:31.591352 systemd-logind[1384]: New session 1 of user core. Oct 8 19:56:31.593362 systemd[1]: Created slice user-500.slice - User Slice of UID 500. Oct 8 19:56:31.605800 etcd-wrapper[1634]: 8c26e4bf18e2: Verifying Checksum Oct 8 19:56:31.605800 etcd-wrapper[1634]: 8c26e4bf18e2: Download complete Oct 8 19:56:31.606916 systemd[1]: Starting user-runtime-dir@500.service - User Runtime Directory /run/user/500... Oct 8 19:56:31.624348 systemd[1]: Finished user-runtime-dir@500.service - User Runtime Directory /run/user/500. Oct 8 19:56:31.634931 systemd[1]: Starting user@500.service - User Manager for UID 500... Oct 8 19:56:31.638490 (systemd)[1670]: pam_unix(systemd-user:session): session opened for user core(uid=500) by (uid=0) Oct 8 19:56:31.781708 systemd[1670]: Queued start job for default target default.target. Oct 8 19:56:31.789370 systemd[1670]: Created slice app.slice - User Application Slice. Oct 8 19:56:31.789404 systemd[1670]: Reached target paths.target - Paths. Oct 8 19:56:31.789423 systemd[1670]: Reached target timers.target - Timers. Oct 8 19:56:31.791500 systemd[1670]: Starting dbus.socket - D-Bus User Message Bus Socket... Oct 8 19:56:31.794529 etcd-wrapper[1634]: 1e59a65f8816: Verifying Checksum Oct 8 19:56:31.794667 etcd-wrapper[1634]: 1e59a65f8816: Download complete Oct 8 19:56:31.801346 etcd-wrapper[1634]: ffbd4ca5f0bd: Verifying Checksum Oct 8 19:56:31.801346 etcd-wrapper[1634]: ffbd4ca5f0bd: Download complete Oct 8 19:56:31.804773 systemd[1670]: Listening on dbus.socket - D-Bus User Message Bus Socket. Oct 8 19:56:31.804945 systemd[1670]: Reached target sockets.target - Sockets. Oct 8 19:56:31.804969 systemd[1670]: Reached target basic.target - Basic System. Oct 8 19:56:31.805008 systemd[1670]: Reached target default.target - Main User Target. Oct 8 19:56:31.805042 systemd[1670]: Startup finished in 158ms. Oct 8 19:56:31.805507 systemd[1]: Started user@500.service - User Manager for UID 500. Oct 8 19:56:31.814715 systemd[1]: Started session-1.scope - Session 1 of User core. Oct 8 19:56:31.880926 systemd[1]: Started sshd@1-10.0.0.64:22-10.0.0.1:57100.service - OpenSSH per-connection server daemon (10.0.0.1:57100). Oct 8 19:56:31.897331 systemd[1]: var-lib-docker-overlay2-859432f04dfce26189ff061a3f5edfd01141c00db52ff9b7600248c68004240d-merged.mount: Deactivated successfully. Oct 8 19:56:31.922144 sshd[1681]: Accepted publickey for core from 10.0.0.1 port 57100 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:31.923711 sshd[1681]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:31.927861 systemd-logind[1384]: New session 2 of user core. Oct 8 19:56:31.938717 systemd[1]: Started session-2.scope - Session 2 of User core. Oct 8 19:56:32.012123 systemd[1]: Started sshd@2-10.0.0.64:22-10.0.0.1:57108.service - OpenSSH per-connection server daemon (10.0.0.1:57108). Oct 8 19:56:32.216411 sshd[1686]: Accepted publickey for core from 10.0.0.1 port 57108 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:32.216891 sshd[1681]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:32.217330 sshd[1686]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:32.222325 systemd[1]: sshd@1-10.0.0.64:22-10.0.0.1:57100.service: Deactivated successfully. Oct 8 19:56:32.224806 systemd[1]: session-2.scope: Deactivated successfully. Oct 8 19:56:32.226964 systemd-logind[1384]: New session 3 of user core. Oct 8 19:56:32.238877 systemd[1]: Started session-3.scope - Session 3 of User core. Oct 8 19:56:32.239672 systemd-logind[1384]: Session 2 logged out. Waiting for processes to exit. Oct 8 19:56:32.240662 systemd-logind[1384]: Removed session 2. Oct 8 19:56:32.297817 sshd[1686]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:32.301491 systemd[1]: sshd@2-10.0.0.64:22-10.0.0.1:57108.service: Deactivated successfully. Oct 8 19:56:32.303610 systemd[1]: session-3.scope: Deactivated successfully. Oct 8 19:56:32.304307 systemd-logind[1384]: Session 3 logged out. Waiting for processes to exit. Oct 8 19:56:32.305449 systemd-logind[1384]: Removed session 3. Oct 8 19:56:32.560952 etcd-wrapper[1634]: d462aa345367: Pull complete Oct 8 19:56:32.752585 systemd[1]: var-lib-docker-overlay2-8ac2e8e8a5791c94a365e4f1e662aff59544360e978ecea69176b12e0ab741e8-merged.mount: Deactivated successfully. Oct 8 19:56:32.798587 etcd-wrapper[1634]: 0f8b424aa0b9: Pull complete Oct 8 19:56:32.856943 systemd[1]: var-lib-docker-overlay2-a013e8828c7e23f0defc88ef9a3bfa5712854098a3e79273784a3b6432f44717-merged.mount: Deactivated successfully. Oct 8 19:56:33.032706 etcd-wrapper[1634]: d557676654e5: Pull complete Oct 8 19:56:33.062080 etcd-wrapper[1634]: c8022d07192e: Pull complete Oct 8 19:56:33.524711 etcd-wrapper[1634]: d858cbc252ad: Pull complete Oct 8 19:56:33.749861 systemd[1]: var-lib-docker-overlay2-ff76bcef556ab7c6a22e403ea12268816a7ada562dfbc6c48432b4e41a3269aa-merged.mount: Deactivated successfully. Oct 8 19:56:33.768529 systemd[1]: var-lib-docker-overlay2-c88e538e554bb7f36993de4e792c43425c938dcf9302876b535b178f43d44465-merged.mount: Deactivated successfully. Oct 8 19:56:33.779798 etcd-wrapper[1634]: 1069fc2daed1: Pull complete Oct 8 19:56:33.795746 systemd[1]: var-lib-docker-overlay2-27ccc71dfe15e2592d15e10b7035a00c8d7ed2f1b5dbfa30a588cedd28947b6b-merged.mount: Deactivated successfully. Oct 8 19:56:33.809216 etcd-wrapper[1634]: b40161cd83fc: Pull complete Oct 8 19:56:33.836865 etcd-wrapper[1634]: 5318d93a3a65: Pull complete Oct 8 19:56:33.868009 etcd-wrapper[1634]: 307c1adadb60: Pull complete Oct 8 19:56:34.311244 etcd-wrapper[1634]: fbb01d9e9dc9: Pull complete Oct 8 19:56:34.568543 etcd-wrapper[1634]: fbfea02ac3cf: Pull complete Oct 8 19:56:34.873942 etcd-wrapper[1634]: 8c26e4bf18e2: Pull complete Oct 8 19:56:34.954738 systemd[1]: var-lib-docker-overlay2-9982e3a1dec23569dd0d09d9c7f99e07297a9cfb1f60ca65a4ce65c78f72829c-merged.mount: Deactivated successfully. Oct 8 19:56:34.965395 etcd-wrapper[1634]: 1e59a65f8816: Pull complete Oct 8 19:56:34.981548 systemd[1]: var-lib-docker-overlay2-110ba370b2c8a714bd50461d4a0d4f08c820d7753c4c05175658e688004094ce-merged.mount: Deactivated successfully. Oct 8 19:56:34.992617 etcd-wrapper[1634]: ffbd4ca5f0bd: Pull complete Oct 8 19:56:35.007474 etcd-wrapper[1634]: Digest: sha256:d967d98a12dc220a1a290794711dba7eba04b8ce465e12b02383d1bfbb33e159 Oct 8 19:56:35.010901 etcd-wrapper[1634]: Status: Downloaded newer image for quay.io/coreos/etcd:v3.5.16 Oct 8 19:56:35.192026 containerd[1398]: time="2024-10-08T19:56:35.191126164Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Oct 8 19:56:35.192026 containerd[1398]: time="2024-10-08T19:56:35.191982279Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Oct 8 19:56:35.192026 containerd[1398]: time="2024-10-08T19:56:35.192006795Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:56:35.192690 containerd[1398]: time="2024-10-08T19:56:35.192125458Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Oct 8 19:56:35.225747 systemd[1]: Started docker-79386cad07a285c21a6a98e2196ab568be42266af44463f5892aa46f5f616b22.scope - libcontainer container 79386cad07a285c21a6a98e2196ab568be42266af44463f5892aa46f5f616b22. Oct 8 19:56:35.245429 systemd-resolved[1271]: Failed to determine the local hostname and LLMNR/mDNS names, ignoring: No such device or address Oct 8 19:56:35.298948 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.298466Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_DATA_DIR","variable-value":"/var/lib/etcd"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.298819Z","caller":"flags/flag.go:113","msg":"recognized and used environment variable","variable-name":"ETCD_NAME","variable-value":"70364a2776d84d5aa068becaca286328"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.298852Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_URL=quay.io/coreos/etcd"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.298862Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_IMAGE_TAG=v3.5.16"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.298868Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_USER=etcd"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.298873Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_SSL_DIR=/etc/ssl/certs"} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.298919Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.298953Z","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.64:2379"]} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.299026Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} Oct 8 19:56:35.299393 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.299033Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} Oct 8 19:56:35.299816 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.299627Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://0.0.0.0:2379"]} Oct 8 19:56:35.300089 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.299891Z","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":"70364a2776d84d5aa068becaca286328","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.64:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"70364a2776d84d5aa068becaca286328=http://localhost:2380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} Oct 8 19:56:35.303318 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.303102Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"2.657103ms"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307380Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307446Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307490Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307498Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307508Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} Oct 8 19:56:35.307669 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.307536Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Oct 8 19:56:35.313142 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:56:35.312895Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} Oct 8 19:56:35.314122 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.313930Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} Oct 8 19:56:35.315118 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.314910Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} Oct 8 19:56:35.316138 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.315829Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} Oct 8 19:56:35.316231 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.315963Z","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"} Oct 8 19:56:35.316370 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316061Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} Oct 8 19:56:35.316370 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316153Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} Oct 8 19:56:35.316370 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316167Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} Oct 8 19:56:35.316370 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316094Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Oct 8 19:56:35.316878 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316744Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} Oct 8 19:56:35.316947 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.316815Z","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"]} Oct 8 19:56:35.318782 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.318660Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} Oct 8 19:56:35.318985 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.318801Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} Oct 8 19:56:35.318985 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:35.318747Z","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.64:2379"],"listen-client-urls":["http://0.0.0.0:2379"],"listen-metrics-urls":[]} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108740Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108808Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108824Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108839Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108845Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108854Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} Oct 8 19:56:36.109237 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.108862Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} Oct 8 19:56:36.109989 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.109618Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} Oct 8 19:56:36.110606 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110221Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:70364a2776d84d5aa068becaca286328 ClientURLs:[http://10.0.0.64:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} Oct 8 19:56:36.110606 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110263Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} Oct 8 19:56:36.110888 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110424Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} Oct 8 19:56:36.110888 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110469Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} Oct 8 19:56:36.110888 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110536Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} Oct 8 19:56:36.110888 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110574Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} Oct 8 19:56:36.110888 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110624Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} Oct 8 19:56:36.111041 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.110838Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} Oct 8 19:56:36.111334 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:56:36.111177Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} Oct 8 19:56:36.111448 systemd[1]: Started etcd-member.service - etcd (System Application Container). Oct 8 19:56:36.111844 systemd[1]: Reached target multi-user.target - Multi-User System. Oct 8 19:56:36.112027 systemd[1]: Startup finished in 1.143s (kernel) + 4.670s (initrd) + 13.971s (userspace) = 19.785s. Oct 8 19:56:42.313116 systemd[1]: Started sshd@3-10.0.0.64:22-10.0.0.1:56566.service - OpenSSH per-connection server daemon (10.0.0.1:56566). Oct 8 19:56:42.351536 sshd[1809]: Accepted publickey for core from 10.0.0.1 port 56566 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:42.353742 sshd[1809]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:42.358894 systemd-logind[1384]: New session 4 of user core. Oct 8 19:56:42.370811 systemd[1]: Started session-4.scope - Session 4 of User core. Oct 8 19:56:42.432101 sshd[1809]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:42.445210 systemd[1]: sshd@3-10.0.0.64:22-10.0.0.1:56566.service: Deactivated successfully. Oct 8 19:56:42.447478 systemd[1]: session-4.scope: Deactivated successfully. Oct 8 19:56:42.449120 systemd-logind[1384]: Session 4 logged out. Waiting for processes to exit. Oct 8 19:56:42.465980 systemd[1]: Started sshd@4-10.0.0.64:22-10.0.0.1:56586.service - OpenSSH per-connection server daemon (10.0.0.1:56586). Oct 8 19:56:42.467084 systemd-logind[1384]: Removed session 4. Oct 8 19:56:42.502218 sshd[1816]: Accepted publickey for core from 10.0.0.1 port 56586 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:42.503906 sshd[1816]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:42.508675 systemd-logind[1384]: New session 5 of user core. Oct 8 19:56:42.518910 systemd[1]: Started session-5.scope - Session 5 of User core. Oct 8 19:56:42.571357 sshd[1816]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:42.584251 systemd[1]: sshd@4-10.0.0.64:22-10.0.0.1:56586.service: Deactivated successfully. Oct 8 19:56:42.586668 systemd[1]: session-5.scope: Deactivated successfully. Oct 8 19:56:42.588411 systemd-logind[1384]: Session 5 logged out. Waiting for processes to exit. Oct 8 19:56:42.589956 systemd[1]: Started sshd@5-10.0.0.64:22-10.0.0.1:56588.service - OpenSSH per-connection server daemon (10.0.0.1:56588). Oct 8 19:56:42.590906 systemd-logind[1384]: Removed session 5. Oct 8 19:56:42.631464 sshd[1823]: Accepted publickey for core from 10.0.0.1 port 56588 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:42.633438 sshd[1823]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:42.638453 systemd-logind[1384]: New session 6 of user core. Oct 8 19:56:42.652766 systemd[1]: Started session-6.scope - Session 6 of User core. Oct 8 19:56:42.711989 sshd[1823]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:42.721108 systemd[1]: sshd@5-10.0.0.64:22-10.0.0.1:56588.service: Deactivated successfully. Oct 8 19:56:42.723490 systemd[1]: session-6.scope: Deactivated successfully. Oct 8 19:56:42.725213 systemd-logind[1384]: Session 6 logged out. Waiting for processes to exit. Oct 8 19:56:42.736972 systemd[1]: Started sshd@6-10.0.0.64:22-10.0.0.1:56600.service - OpenSSH per-connection server daemon (10.0.0.1:56600). Oct 8 19:56:42.738970 systemd-logind[1384]: Removed session 6. Oct 8 19:56:42.774137 sshd[1830]: Accepted publickey for core from 10.0.0.1 port 56600 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:42.776212 sshd[1830]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:42.785099 systemd-logind[1384]: New session 7 of user core. Oct 8 19:56:42.795116 systemd[1]: Started session-7.scope - Session 7 of User core. Oct 8 19:56:42.856832 sudo[1833]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/sbin/setenforce 1 Oct 8 19:56:42.857265 sudo[1833]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Oct 8 19:56:42.880622 sudo[1833]: pam_unix(sudo:session): session closed for user root Oct 8 19:56:42.882802 sshd[1830]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:42.906625 systemd[1]: sshd@6-10.0.0.64:22-10.0.0.1:56600.service: Deactivated successfully. Oct 8 19:56:42.908466 systemd[1]: session-7.scope: Deactivated successfully. Oct 8 19:56:42.910022 systemd-logind[1384]: Session 7 logged out. Waiting for processes to exit. Oct 8 19:56:42.911527 systemd[1]: Started sshd@7-10.0.0.64:22-10.0.0.1:56616.service - OpenSSH per-connection server daemon (10.0.0.1:56616). Oct 8 19:56:42.912504 systemd-logind[1384]: Removed session 7. Oct 8 19:56:42.959447 sshd[1838]: Accepted publickey for core from 10.0.0.1 port 56616 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:42.961480 sshd[1838]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:42.966447 systemd-logind[1384]: New session 8 of user core. Oct 8 19:56:42.977782 systemd[1]: Started session-8.scope - Session 8 of User core. Oct 8 19:56:43.036869 sudo[1842]: 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 Oct 8 19:56:43.037311 sudo[1842]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Oct 8 19:56:43.042603 sudo[1842]: pam_unix(sudo:session): session closed for user root Oct 8 19:56:43.051942 sudo[1841]: core : PWD=/home/core ; USER=root ; COMMAND=/usr/bin/systemctl restart audit-rules Oct 8 19:56:43.052457 sudo[1841]: pam_unix(sudo:session): session opened for user root(uid=0) by core(uid=500) Oct 8 19:56:43.073900 systemd[1]: Stopping audit-rules.service - Load Security Auditing Rules... Oct 8 19:56:43.076065 auditctl[1845]: No rules Oct 8 19:56:43.076632 systemd[1]: audit-rules.service: Deactivated successfully. Oct 8 19:56:43.077005 systemd[1]: Stopped audit-rules.service - Load Security Auditing Rules. Oct 8 19:56:43.080465 systemd[1]: Starting audit-rules.service - Load Security Auditing Rules... Oct 8 19:56:43.115039 augenrules[1863]: No rules Oct 8 19:56:43.116059 systemd[1]: Finished audit-rules.service - Load Security Auditing Rules. Oct 8 19:56:43.117584 sudo[1841]: pam_unix(sudo:session): session closed for user root Oct 8 19:56:43.119537 sshd[1838]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:43.126922 systemd[1]: sshd@7-10.0.0.64:22-10.0.0.1:56616.service: Deactivated successfully. Oct 8 19:56:43.128989 systemd[1]: session-8.scope: Deactivated successfully. Oct 8 19:56:43.131269 systemd-logind[1384]: Session 8 logged out. Waiting for processes to exit. Oct 8 19:56:43.140934 systemd[1]: Started sshd@8-10.0.0.64:22-10.0.0.1:56630.service - OpenSSH per-connection server daemon (10.0.0.1:56630). Oct 8 19:56:43.142205 systemd-logind[1384]: Removed session 8. Oct 8 19:56:43.174632 sshd[1871]: Accepted publickey for core from 10.0.0.1 port 56630 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:43.176279 sshd[1871]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:43.180594 systemd-logind[1384]: New session 9 of user core. Oct 8 19:56:43.199791 systemd[1]: Started session-9.scope - Session 9 of User core. Oct 8 19:56:43.252873 sshd[1871]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:43.260503 systemd[1]: sshd@8-10.0.0.64:22-10.0.0.1:56630.service: Deactivated successfully. Oct 8 19:56:43.262465 systemd[1]: session-9.scope: Deactivated successfully. Oct 8 19:56:43.264161 systemd-logind[1384]: Session 9 logged out. Waiting for processes to exit. Oct 8 19:56:43.265528 systemd[1]: Started sshd@9-10.0.0.64:22-10.0.0.1:56636.service - OpenSSH per-connection server daemon (10.0.0.1:56636). Oct 8 19:56:43.266371 systemd-logind[1384]: Removed session 9. Oct 8 19:56:43.302280 sshd[1880]: Accepted publickey for core from 10.0.0.1 port 56636 ssh2: RSA SHA256:OJWXIxWV5/ezNshFugVkIfLhrnHf7T3OS94qlXwAt6w Oct 8 19:56:43.304106 sshd[1880]: pam_unix(sshd:session): session opened for user core(uid=500) by core(uid=0) Oct 8 19:56:43.308591 systemd-logind[1384]: New session 10 of user core. Oct 8 19:56:43.318731 systemd[1]: Started session-10.scope - Session 10 of User core. Oct 8 19:56:43.523762 sshd[1880]: pam_unix(sshd:session): session closed for user core Oct 8 19:56:43.528268 systemd[1]: sshd@9-10.0.0.64:22-10.0.0.1:56636.service: Deactivated successfully. Oct 8 19:56:43.530537 systemd[1]: session-10.scope: Deactivated successfully. Oct 8 19:56:43.531156 systemd-logind[1384]: Session 10 logged out. Waiting for processes to exit. Oct 8 19:56:43.532323 systemd-logind[1384]: Removed session 10. Oct 8 19:57:10.333589 update_engine[1386]: I20241008 19:57:10.333426 1386 update_attempter.cc:509] Updating boot flags... Oct 8 19:57:10.362598 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1900) Oct 8 19:57:10.416658 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1904) Oct 8 19:57:10.470607 kernel: BTRFS warning: duplicate device /dev/vda3 devid 1 generation 38 scanned by (udev-worker) (1904) Oct 8 19:57:47.391617 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391040Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.487016ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:14"} Oct 8 19:57:47.391617 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391126Z","caller":"traceutil/trace.go:171","msg":"trace[1884419904] linearizableReadLoop","detail":"{readStateIndex:16; appliedIndex:15; }","duration":"244.106633ms","start":"2024-10-08T19:57:47.147001Z","end":"2024-10-08T19:57:47.391108Z","steps":["trace[1884419904] 'read index received' (duration: 127.266684ms)","trace[1884419904] 'applied index is now lower than readState.Index' (duration: 116.839328ms)"],"step_count":2} Oct 8 19:57:47.391617 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391175Z","caller":"traceutil/trace.go:171","msg":"trace[756593754] transaction","detail":"{read_only:false; response_revision:12; number_of_response:1; }","duration":"252.303603ms","start":"2024-10-08T19:57:47.138865Z","end":"2024-10-08T19:57:47.391169Z","steps":["trace[756593754] 'process raft request' (duration: 135.327348ms)","trace[756593754] 'compare' (duration: 116.360728ms)"],"step_count":2} Oct 8 19:57:47.392467 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391263Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"265.82018ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/kube-system\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.392467 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391283Z","caller":"traceutil/trace.go:171","msg":"trace[1574051443] range","detail":"{range_begin:/registry/namespaces/kube-system; range_end:; response_count:0; response_revision:12; }","duration":"265.884671ms","start":"2024-10-08T19:57:47.125393Z","end":"2024-10-08T19:57:47.391277Z","steps":["trace[1574051443] 'agreement among raft nodes before linearized reading' (duration: 265.829237ms)"],"step_count":1} Oct 8 19:57:47.392467 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391326Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"332.981025ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/localhost\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.392467 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391339Z","caller":"traceutil/trace.go:171","msg":"trace[84068561] range","detail":"{range_begin:/registry/csinodes/localhost; range_end:; response_count:0; response_revision:12; }","duration":"333.014768ms","start":"2024-10-08T19:57:47.058320Z","end":"2024-10-08T19:57:47.391335Z","steps":["trace[84068561] 'agreement among raft nodes before linearized reading' (duration: 332.996724ms)"],"step_count":1} Oct 8 19:57:47.392467 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391354Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:57:47.058303Z","time spent":"333.045526ms","remote":"10.0.0.67:34434","response type":"/etcdserverpb.KV/Range","request count":0,"request size":30,"response count":0,"response size":28,"request content":"key:\"/registry/csinodes/localhost\" "} Oct 8 19:57:47.392638 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391349Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"288.228542ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/kube-system\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.392638 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391404Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"339.661597ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.392638 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391445Z","caller":"traceutil/trace.go:171","msg":"trace[77487504] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:12; }","duration":"339.702344ms","start":"2024-10-08T19:57:47.051716Z","end":"2024-10-08T19:57:47.391418Z","steps":["trace[77487504] 'agreement among raft nodes before linearized reading' (duration: 339.678719ms)"],"step_count":1} Oct 8 19:57:47.392638 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391449Z","caller":"traceutil/trace.go:171","msg":"trace[1816545356] range","detail":"{range_begin:/registry/namespaces/kube-system; range_end:; response_count:0; response_revision:12; }","duration":"288.336855ms","start":"2024-10-08T19:57:47.103066Z","end":"2024-10-08T19:57:47.391402Z","steps":["trace[1816545356] 'agreement among raft nodes before linearized reading' (duration: 288.219244ms)"],"step_count":1} Oct 8 19:57:47.392638 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391460Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:57:47.051710Z","time spent":"339.745083ms","remote":"10.0.0.67:34012","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} Oct 8 19:57:47.392787 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.391413Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"274.943951ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/default\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.392787 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.391532Z","caller":"traceutil/trace.go:171","msg":"trace[92467851] range","detail":"{range_begin:/registry/namespaces/default; range_end:; response_count:0; response_revision:12; }","duration":"275.110203ms","start":"2024-10-08T19:57:47.116406Z","end":"2024-10-08T19:57:47.391516Z","steps":["trace[92467851] 'agreement among raft nodes before linearized reading' (duration: 274.930055ms)"],"step_count":1} Oct 8 19:57:47.409021 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408342Z","caller":"traceutil/trace.go:171","msg":"trace[2117420363] transaction","detail":"{read_only:false; number_of_response:0; response_revision:13; }","duration":"258.603811ms","start":"2024-10-08T19:57:47.149730Z","end":"2024-10-08T19:57:47.408333Z","steps":["trace[2117420363] 'process raft request' (duration: 258.569416ms)"],"step_count":1} Oct 8 19:57:47.409021 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408433Z","caller":"traceutil/trace.go:171","msg":"trace[1430066518] transaction","detail":"{read_only:false; response_revision:13; number_of_response:1; }","duration":"258.80031ms","start":"2024-10-08T19:57:47.149623Z","end":"2024-10-08T19:57:47.408423Z","steps":["trace[1430066518] 'process raft request' (duration: 258.633326ms)"],"step_count":1} Oct 8 19:57:47.409021 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408442Z","caller":"traceutil/trace.go:171","msg":"trace[2011813623] transaction","detail":"{read_only:false; response_revision:15; number_of_response:1; }","duration":"257.967406ms","start":"2024-10-08T19:57:47.150470Z","end":"2024-10-08T19:57:47.408437Z","steps":["trace[2011813623] 'process raft request' (duration: 257.91618ms)"],"step_count":1} Oct 8 19:57:47.409021 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408517Z","caller":"traceutil/trace.go:171","msg":"trace[507957233] transaction","detail":"{read_only:false; response_revision:14; number_of_response:1; }","duration":"258.229849ms","start":"2024-10-08T19:57:47.150281Z","end":"2024-10-08T19:57:47.408511Z","steps":["trace[507957233] 'process raft request' (duration: 258.031897ms)"],"step_count":1} Oct 8 19:57:47.409021 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408548Z","caller":"traceutil/trace.go:171","msg":"trace[2051115007] transaction","detail":"{read_only:false; response_revision:18; number_of_response:1; }","duration":"257.689315ms","start":"2024-10-08T19:57:47.150851Z","end":"2024-10-08T19:57:47.408540Z","steps":["trace[2051115007] 'process raft request' (duration: 257.597362ms)"],"step_count":1} Oct 8 19:57:47.409277 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408653Z","caller":"traceutil/trace.go:171","msg":"trace[1143321154] transaction","detail":"{read_only:false; response_revision:19; number_of_response:1; }","duration":"200.348727ms","start":"2024-10-08T19:57:47.208296Z","end":"2024-10-08T19:57:47.408645Z","steps":["trace[1143321154] 'process raft request' (duration: 200.170152ms)"],"step_count":1} Oct 8 19:57:47.409277 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408663Z","caller":"traceutil/trace.go:171","msg":"trace[1865378066] transaction","detail":"{read_only:false; response_revision:17; number_of_response:1; }","duration":"257.89467ms","start":"2024-10-08T19:57:47.150733Z","end":"2024-10-08T19:57:47.408628Z","steps":["trace[1865378066] 'process raft request' (duration: 257.700626ms)"],"step_count":1} Oct 8 19:57:47.409277 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408665Z","caller":"traceutil/trace.go:171","msg":"trace[905423194] transaction","detail":"{read_only:false; response_revision:16; number_of_response:1; }","duration":"257.940576ms","start":"2024-10-08T19:57:47.150692Z","end":"2024-10-08T19:57:47.408633Z","steps":["trace[905423194] 'process raft request' (duration: 257.719271ms)"],"step_count":1} Oct 8 19:57:47.409277 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.408725Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"257.824518ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/certificatesigningrequests/csr-bfc4w\" ","response":"range_response_count:1 size:862"} Oct 8 19:57:47.409277 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.408758Z","caller":"traceutil/trace.go:171","msg":"trace[2028466406] range","detail":"{range_begin:/registry/certificatesigningrequests/csr-bfc4w; range_end:; response_count:1; response_revision:19; }","duration":"257.87863ms","start":"2024-10-08T19:57:47.150870Z","end":"2024-10-08T19:57:47.408749Z","steps":["trace[2028466406] 'agreement among raft nodes before linearized reading' (duration: 257.803328ms)"],"step_count":1} Oct 8 19:57:47.681684 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.681030Z","caller":"traceutil/trace.go:171","msg":"trace[1699470360] linearizableReadLoop","detail":"{readStateIndex:33; appliedIndex:30; }","duration":"207.854162ms","start":"2024-10-08T19:57:47.473162Z","end":"2024-10-08T19:57:47.681016Z","steps":["trace[1699470360] 'read index received' (duration: 135.605906ms)","trace[1699470360] 'applied index is now lower than readState.Index' (duration: 72.247664ms)"],"step_count":2} Oct 8 19:57:47.681684 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.681085Z","caller":"traceutil/trace.go:171","msg":"trace[817048468] transaction","detail":"{read_only:false; response_revision:27; number_of_response:1; }","duration":"257.444468ms","start":"2024-10-08T19:57:47.423618Z","end":"2024-10-08T19:57:47.681063Z","steps":["trace[817048468] 'process raft request' (duration: 257.34388ms)"],"step_count":1} Oct 8 19:57:47.681684 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.681153Z","caller":"traceutil/trace.go:171","msg":"trace[161589780] transaction","detail":"{read_only:false; response_revision:28; number_of_response:1; }","duration":"230.919166ms","start":"2024-10-08T19:57:47.450226Z","end":"2024-10-08T19:57:47.681145Z","steps":["trace[161589780] 'process raft request' (duration: 230.770337ms)"],"step_count":1} Oct 8 19:57:47.681684 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.681092Z","caller":"traceutil/trace.go:171","msg":"trace[1382091499] transaction","detail":"{read_only:false; response_revision:26; number_of_response:1; }","duration":"258.000161ms","start":"2024-10-08T19:57:47.423080Z","end":"2024-10-08T19:57:47.681080Z","steps":["trace[1382091499] 'process raft request' (duration: 185.584271ms)","trace[1382091499] 'compare' (duration: 72.138749ms)"],"step_count":2} Oct 8 19:57:47.681684 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.681233Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"236.032366ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/default\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.681985 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.681263Z","caller":"traceutil/trace.go:171","msg":"trace[1305531657] range","detail":"{range_begin:/registry/namespaces/default; range_end:; response_count:0; response_revision:28; }","duration":"236.086337ms","start":"2024-10-08T19:57:47.445169Z","end":"2024-10-08T19:57:47.681255Z","steps":["trace[1305531657] 'agreement among raft nodes before linearized reading' (duration: 236.011567ms)"],"step_count":1} Oct 8 19:57:47.741383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.740946Z","caller":"traceutil/trace.go:171","msg":"trace[516573114] transaction","detail":"{read_only:false; response_revision:31; number_of_response:1; }","duration":"264.81813ms","start":"2024-10-08T19:57:47.476108Z","end":"2024-10-08T19:57:47.740927Z","steps":["trace[516573114] 'process raft request' (duration: 264.745143ms)"],"step_count":1} Oct 8 19:57:47.741383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.740959Z","caller":"traceutil/trace.go:171","msg":"trace[1275604750] transaction","detail":"{read_only:false; response_revision:32; number_of_response:1; }","duration":"264.759953ms","start":"2024-10-08T19:57:47.476187Z","end":"2024-10-08T19:57:47.740947Z","steps":["trace[1275604750] 'process raft request' (duration: 264.676335ms)"],"step_count":1} Oct 8 19:57:47.741383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.740952Z","caller":"traceutil/trace.go:171","msg":"trace[1129442437] transaction","detail":"{read_only:false; response_revision:29; number_of_response:1; }","duration":"265.400615ms","start":"2024-10-08T19:57:47.475542Z","end":"2024-10-08T19:57:47.740942Z","steps":["trace[1129442437] 'process raft request' (duration: 265.2276ms)"],"step_count":1} Oct 8 19:57:47.741383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.741035Z","caller":"traceutil/trace.go:171","msg":"trace[457450436] transaction","detail":"{read_only:false; response_revision:30; number_of_response:1; }","duration":"265.170003ms","start":"2024-10-08T19:57:47.475858Z","end":"2024-10-08T19:57:47.741028Z","steps":["trace[457450436] 'process raft request' (duration: 264.98229ms)"],"step_count":1} Oct 8 19:57:47.741383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.741056Z","caller":"traceutil/trace.go:171","msg":"trace[1860184036] transaction","detail":"{read_only:false; response_revision:33; number_of_response:1; }","duration":"264.762417ms","start":"2024-10-08T19:57:47.476289Z","end":"2024-10-08T19:57:47.741052Z","steps":["trace[1860184036] 'process raft request' (duration: 264.58869ms)"],"step_count":1} Oct 8 19:57:47.741693 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.741129Z","caller":"traceutil/trace.go:171","msg":"trace[200711775] transaction","detail":"{read_only:false; response_revision:34; number_of_response:1; }","duration":"264.607085ms","start":"2024-10-08T19:57:47.476515Z","end":"2024-10-08T19:57:47.741122Z","steps":["trace[200711775] 'process raft request' (duration: 264.385238ms)"],"step_count":1} Oct 8 19:57:47.741693 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.741151Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"146.351385ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/apiserver-l2yubf4cvcl5c7a3wrubrwqdve\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.741693 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.741173Z","caller":"traceutil/trace.go:171","msg":"trace[1955213753] range","detail":"{range_begin:/registry/leases/kube-system/apiserver-l2yubf4cvcl5c7a3wrubrwqdve; range_end:; response_count:0; response_revision:34; }","duration":"146.406748ms","start":"2024-10-08T19:57:47.594758Z","end":"2024-10-08T19:57:47.741165Z","steps":["trace[1955213753] 'agreement among raft nodes before linearized reading' (duration: 146.335986ms)"],"step_count":1} Oct 8 19:57:47.741861 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:47.741253Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"264.962652ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/resourcequotas/kube-public/\" range_end:\"/registry/resourcequotas/kube-public0\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:47.741861 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:47.741293Z","caller":"traceutil/trace.go:171","msg":"trace[1373065492] range","detail":"{range_begin:/registry/resourcequotas/kube-public/; range_end:/registry/resourcequotas/kube-public0; response_count:0; response_revision:34; }","duration":"265.135837ms","start":"2024-10-08T19:57:47.476145Z","end":"2024-10-08T19:57:47.741281Z","steps":["trace[1373065492] 'agreement among raft nodes before linearized reading' (duration: 264.958915ms)"],"step_count":1} Oct 8 19:57:48.186906 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186338Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"216.776443ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:14"} Oct 8 19:57:48.186906 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186456Z","caller":"traceutil/trace.go:171","msg":"trace[2094842223] linearizableReadLoop","detail":"{readStateIndex:46; appliedIndex:44; }","duration":"380.377895ms","start":"2024-10-08T19:57:47.806067Z","end":"2024-10-08T19:57:48.186445Z","steps":["trace[2094842223] 'read index received' (duration: 163.33426ms)","trace[2094842223] 'applied index is now lower than readState.Index' (duration: 217.043164ms)"],"step_count":2} Oct 8 19:57:48.186906 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186508Z","caller":"traceutil/trace.go:171","msg":"trace[1495967079] transaction","detail":"{read_only:false; response_revision:40; number_of_response:1; }","duration":"405.773374ms","start":"2024-10-08T19:57:47.780728Z","end":"2024-10-08T19:57:48.186501Z","steps":["trace[1495967079] 'process raft request' (duration: 188.533481ms)","trace[1495967079] 'compare' (duration: 216.679852ms)"],"step_count":2} Oct 8 19:57:48.187172 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186543Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:57:47.780718Z","time spent":"405.807499ms","remote":"10.0.0.67:34104","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":350,"response count":0,"response size":38,"request content":"compare: success:> failure:<>"} Oct 8 19:57:48.187172 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186574Z","caller":"traceutil/trace.go:171","msg":"trace[748838563] transaction","detail":"{read_only:false; response_revision:41; number_of_response:1; }","duration":"404.551951ms","start":"2024-10-08T19:57:47.781977Z","end":"2024-10-08T19:57:48.186529Z","steps":["trace[748838563] 'process raft request' (duration: 404.437546ms)"],"step_count":1} Oct 8 19:57:48.187172 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186714Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:57:47.781957Z","time spent":"404.741235ms","remote":"10.0.0.67:34470","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":637,"response count":0,"response size":38,"request content":"compare: success:> failure:<>"} Oct 8 19:57:48.187172 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186697Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"236.503901ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/priorityclasses/system-node-critical\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:48.187383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186751Z","caller":"traceutil/trace.go:171","msg":"trace[1317420688] range","detail":"{range_begin:/registry/priorityclasses/system-node-critical; range_end:; response_count:0; response_revision:41; }","duration":"236.591347ms","start":"2024-10-08T19:57:47.950147Z","end":"2024-10-08T19:57:48.186738Z","steps":["trace[1317420688] 'agreement among raft nodes before linearized reading' (duration: 236.478654ms)"],"step_count":1} Oct 8 19:57:48.187383 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186800Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"380.726069ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/default\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:48.187383 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186821Z","caller":"traceutil/trace.go:171","msg":"trace[281021975] range","detail":"{range_begin:/registry/namespaces/default; range_end:; response_count:0; response_revision:41; }","duration":"380.764651ms","start":"2024-10-08T19:57:47.806049Z","end":"2024-10-08T19:57:48.186814Z","steps":["trace[281021975] 'agreement among raft nodes before linearized reading' (duration: 380.729655ms)"],"step_count":1} Oct 8 19:57:48.187383 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186835Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"236.644395ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:48.187383 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.186840Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:57:47.806041Z","time spent":"380.794668ms","remote":"10.0.0.67:34104","response type":"/etcdserverpb.KV/Range","request count":0,"request size":30,"response count":0,"response size":28,"request content":"key:\"/registry/namespaces/default\" "} Oct 8 19:57:48.187515 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.186849Z","caller":"traceutil/trace.go:171","msg":"trace[1414732755] range","detail":"{range_begin:/registry/clusterroles/; range_end:/registry/clusterroles0; response_count:0; response_revision:41; }","duration":"236.667138ms","start":"2024-10-08T19:57:47.950177Z","end":"2024-10-08T19:57:48.186844Z","steps":["trace[1414732755] 'agreement among raft nodes before linearized reading' (duration: 236.645748ms)"],"step_count":1} Oct 8 19:57:48.425103 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424418Z","caller":"traceutil/trace.go:171","msg":"trace[1703867467] linearizableReadLoop","detail":"{readStateIndex:48; appliedIndex:46; }","duration":"234.490778ms","start":"2024-10-08T19:57:48.189907Z","end":"2024-10-08T19:57:48.424398Z","steps":["trace[1703867467] 'read index received' (duration: 88.022932ms)","trace[1703867467] 'applied index is now lower than readState.Index' (duration: 146.466995ms)"],"step_count":2} Oct 8 19:57:48.425103 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424476Z","caller":"traceutil/trace.go:171","msg":"trace[118607111] transaction","detail":"{read_only:false; response_revision:45; number_of_response:1; }","duration":"233.579838ms","start":"2024-10-08T19:57:48.190892Z","end":"2024-10-08T19:57:48.424472Z","steps":["trace[118607111] 'process raft request' (duration: 233.47425ms)"],"step_count":1} Oct 8 19:57:48.425103 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424483Z","caller":"traceutil/trace.go:171","msg":"trace[1247519091] transaction","detail":"{read_only:false; response_revision:44; number_of_response:1; }","duration":"234.415647ms","start":"2024-10-08T19:57:48.190051Z","end":"2024-10-08T19:57:48.424467Z","steps":["trace[1247519091] 'process raft request' (duration: 234.287717ms)"],"step_count":1} Oct 8 19:57:48.425103 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.424555Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"234.639597ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/system:aggregate-to-admin\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:48.425103 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424430Z","caller":"traceutil/trace.go:171","msg":"trace[99293211] transaction","detail":"{read_only:false; response_revision:43; number_of_response:1; }","duration":"234.725279ms","start":"2024-10-08T19:57:48.189684Z","end":"2024-10-08T19:57:48.424409Z","steps":["trace[99293211] 'process raft request' (duration: 210.062337ms)","trace[99293211] 'compare' (duration: 24.481151ms)"],"step_count":2} Oct 8 19:57:48.425768 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424607Z","caller":"traceutil/trace.go:171","msg":"trace[388216528] range","detail":"{range_begin:/registry/clusterroles/system:aggregate-to-admin; range_end:; response_count:0; response_revision:45; }","duration":"234.715972ms","start":"2024-10-08T19:57:48.189883Z","end":"2024-10-08T19:57:48.424599Z","steps":["trace[388216528] 'agreement among raft nodes before linearized reading' (duration: 234.632354ms)"],"step_count":1} Oct 8 19:57:48.425768 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.424614Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"182.287804ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/namespaces/default\" ","response":"range_response_count:1 size:338"} Oct 8 19:57:48.425768 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424635Z","caller":"traceutil/trace.go:171","msg":"trace[1546079187] range","detail":"{range_begin:/registry/namespaces/default; range_end:; response_count:1; response_revision:45; }","duration":"182.332007ms","start":"2024-10-08T19:57:48.242297Z","end":"2024-10-08T19:57:48.424629Z","steps":["trace[1546079187] 'agreement among raft nodes before linearized reading' (duration: 182.256875ms)"],"step_count":1} Oct 8 19:57:48.425768 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:57:48.424651Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"144.80804ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/priorityclasses/system-cluster-critical\" ","response":"range_response_count:0 size:4"} Oct 8 19:57:48.425768 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.424674Z","caller":"traceutil/trace.go:171","msg":"trace[2050111226] range","detail":"{range_begin:/registry/priorityclasses/system-cluster-critical; range_end:; response_count:0; response_revision:45; }","duration":"144.873783ms","start":"2024-10-08T19:57:48.279794Z","end":"2024-10-08T19:57:48.424668Z","steps":["trace[2050111226] 'agreement among raft nodes before linearized reading' (duration: 144.819111ms)"],"step_count":1} Oct 8 19:57:48.589505 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.589027Z","caller":"traceutil/trace.go:171","msg":"trace[38305311] transaction","detail":"{read_only:false; response_revision:54; number_of_response:1; }","duration":"121.840842ms","start":"2024-10-08T19:57:48.467169Z","end":"2024-10-08T19:57:48.589010Z","steps":["trace[38305311] 'process raft request' (duration: 121.729753ms)"],"step_count":1} Oct 8 19:57:48.589505 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:48.589083Z","caller":"traceutil/trace.go:171","msg":"trace[1815087274] transaction","detail":"{read_only:false; response_revision:53; number_of_response:1; }","duration":"122.139673ms","start":"2024-10-08T19:57:48.466929Z","end":"2024-10-08T19:57:48.589068Z","steps":["trace[1815087274] 'process raft request' (duration: 62.887995ms)","trace[1815087274] 'compare' (duration: 58.982312ms)"],"step_count":2} Oct 8 19:57:49.809742 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:49.809285Z","caller":"traceutil/trace.go:171","msg":"trace[985252279] transaction","detail":"{read_only:false; response_revision:199; number_of_response:1; }","duration":"148.630515ms","start":"2024-10-08T19:57:49.660627Z","end":"2024-10-08T19:57:49.809258Z","steps":["trace[985252279] 'process raft request' (duration: 119.764698ms)","trace[985252279] 'compare' (duration: 28.780267ms)"],"step_count":2} Oct 8 19:57:50.313509 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:50.313083Z","caller":"traceutil/trace.go:171","msg":"trace[374361940] transaction","detail":"{read_only:false; response_revision:226; number_of_response:1; }","duration":"116.025505ms","start":"2024-10-08T19:57:50.197032Z","end":"2024-10-08T19:57:50.313058Z","steps":["trace[374361940] 'process raft request' (duration: 88.690684ms)","trace[374361940] 'compare' (duration: 27.200489ms)"],"step_count":2} Oct 8 19:57:53.246708 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:57:53.246213Z","caller":"traceutil/trace.go:171","msg":"trace[1581434661] transaction","detail":"{read_only:false; response_revision:309; number_of_response:1; }","duration":"175.504981ms","start":"2024-10-08T19:57:53.070687Z","end":"2024-10-08T19:57:53.246192Z","steps":["trace[1581434661] 'process raft request' (duration: 159.666144ms)","trace[1581434661] 'compare' (duration: 15.750271ms)"],"step_count":2} Oct 8 19:58:00.789968 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:00.789541Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"156.426041ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/statefulset-controller\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:00.789968 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:00.789653Z","caller":"traceutil/trace.go:171","msg":"trace[1192501048] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/statefulset-controller; range_end:; response_count:0; response_revision:346; }","duration":"156.564338ms","start":"2024-10-08T19:58:00.633074Z","end":"2024-10-08T19:58:00.789639Z","steps":["trace[1192501048] 'range keys from in-memory index tree' (duration: 156.389356ms)"],"step_count":1} Oct 8 19:58:05.217082 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:05.216536Z","caller":"traceutil/trace.go:171","msg":"trace[1142815238] transaction","detail":"{read_only:false; response_revision:378; number_of_response:1; }","duration":"103.06649ms","start":"2024-10-08T19:58:05.113448Z","end":"2024-10-08T19:58:05.216515Z","steps":["trace[1142815238] 'process raft request' (duration: 102.915885ms)"],"step_count":1} Oct 8 19:58:11.368040 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:11.367661Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"104.278265ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} Oct 8 19:58:11.368040 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.367752Z","caller":"traceutil/trace.go:171","msg":"trace[811968513] linearizableReadLoop","detail":"{readStateIndex:501; appliedIndex:500; }","duration":"220.886532ms","start":"2024-10-08T19:58:11.146852Z","end":"2024-10-08T19:58:11.367739Z","steps":["trace[811968513] 'read index received' (duration: 116.372517ms)","trace[811968513] 'applied index is now lower than readState.Index' (duration: 104.513176ms)"],"step_count":2} Oct 8 19:58:11.368040 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.367818Z","caller":"traceutil/trace.go:171","msg":"trace[2055844776] transaction","detail":"{read_only:false; response_revision:489; number_of_response:1; }","duration":"287.966612ms","start":"2024-10-08T19:58:11.079822Z","end":"2024-10-08T19:58:11.367788Z","steps":["trace[2055844776] 'process raft request' (duration: 183.393921ms)","trace[2055844776] 'compare' (duration: 104.186ms)"],"step_count":2} Oct 8 19:58:11.368040 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:11.367839Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"220.996598ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumidentities.cilium.io\" ","response":"range_response_count:1 size:4673"} Oct 8 19:58:11.368726 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.367891Z","caller":"traceutil/trace.go:171","msg":"trace[1678278002] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumidentities.cilium.io; range_end:; response_count:1; response_revision:489; }","duration":"221.070403ms","start":"2024-10-08T19:58:11.146813Z","end":"2024-10-08T19:58:11.367883Z","steps":["trace[1678278002] 'agreement among raft nodes before linearized reading' (duration: 221.000602ms)"],"step_count":1} Oct 8 19:58:11.657141 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.656441Z","caller":"traceutil/trace.go:171","msg":"trace[1233912950] transaction","detail":"{read_only:false; response_revision:490; number_of_response:1; }","duration":"227.723318ms","start":"2024-10-08T19:58:11.428681Z","end":"2024-10-08T19:58:11.656404Z","steps":["trace[1233912950] 'process raft request' (duration: 168.453865ms)","trace[1233912950] 'compare' (duration: 59.119394ms)"],"step_count":2} Oct 8 19:58:11.657141 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.656460Z","caller":"traceutil/trace.go:171","msg":"trace[674803495] linearizableReadLoop","detail":"{readStateIndex:502; appliedIndex:501; }","duration":"110.365861ms","start":"2024-10-08T19:58:11.546073Z","end":"2024-10-08T19:58:11.656439Z","steps":["trace[674803495] 'read index received' (duration: 50.924725ms)","trace[674803495] 'applied index is now lower than readState.Index' (duration: 59.439414ms)"],"step_count":2} Oct 8 19:58:11.657141 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:11.656544Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"110.456885ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumnodes.cilium.io\" ","response":"range_response_count:1 size:21762"} Oct 8 19:58:11.657141 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:11.656603Z","caller":"traceutil/trace.go:171","msg":"trace[1617545469] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumnodes.cilium.io; range_end:; response_count:1; response_revision:491; }","duration":"110.553453ms","start":"2024-10-08T19:58:11.546041Z","end":"2024-10-08T19:58:11.656595Z","steps":["trace[1617545469] 'agreement among raft nodes before linearized reading' (duration: 110.454454ms)"],"step_count":1} Oct 8 19:58:17.869699 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:17.869288Z","caller":"traceutil/trace.go:171","msg":"trace[2121870716] transaction","detail":"{read_only:false; response_revision:506; number_of_response:1; }","duration":"100.072945ms","start":"2024-10-08T19:58:17.769197Z","end":"2024-10-08T19:58:17.869270Z","steps":["trace[2121870716] 'process raft request' (duration: 82.442903ms)","trace[2121870716] 'compare' (duration: 17.482167ms)"],"step_count":2} Oct 8 19:58:18.298282 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.297782Z","caller":"traceutil/trace.go:171","msg":"trace[1430303969] transaction","detail":"{read_only:false; response_revision:509; number_of_response:1; }","duration":"234.442956ms","start":"2024-10-08T19:58:18.063322Z","end":"2024-10-08T19:58:18.297765Z","steps":["trace[1430303969] 'process raft request' (duration: 234.327242ms)"],"step_count":1} Oct 8 19:58:18.298282 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.297941Z","caller":"traceutil/trace.go:171","msg":"trace[376134922] transaction","detail":"{read_only:false; number_of_response:1; response_revision:509; }","duration":"234.07952ms","start":"2024-10-08T19:58:18.063852Z","end":"2024-10-08T19:58:18.297932Z","steps":["trace[376134922] 'process raft request' (duration: 233.884951ms)"],"step_count":1} Oct 8 19:58:18.298282 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.297942Z","caller":"traceutil/trace.go:171","msg":"trace[2020070981] linearizableReadLoop","detail":"{readStateIndex:523; appliedIndex:520; }","duration":"233.250024ms","start":"2024-10-08T19:58:18.064669Z","end":"2024-10-08T19:58:18.297919Z","steps":["trace[2020070981] 'read index received' (duration: 40.967934ms)","trace[2020070981] 'applied index is now lower than readState.Index' (duration: 192.280419ms)"],"step_count":2} Oct 8 19:58:18.298282 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.298112Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"233.430042ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/resourcequotas/kube-system/\" range_end:\"/registry/resourcequotas/kube-system0\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:18.298707 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.298207Z","caller":"traceutil/trace.go:171","msg":"trace[522205954] range","detail":"{range_begin:/registry/resourcequotas/kube-system/; range_end:/registry/resourcequotas/kube-system0; response_count:0; response_revision:509; }","duration":"233.555284ms","start":"2024-10-08T19:58:18.064642Z","end":"2024-10-08T19:58:18.298197Z","steps":["trace[522205954] 'agreement among raft nodes before linearized reading' (duration: 233.389339ms)"],"step_count":1} Oct 8 19:58:18.298707 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.298131Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"118.389198ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/10.0.0.78\" ","response":"range_response_count:1 size:2131"} Oct 8 19:58:18.298707 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.298278Z","caller":"traceutil/trace.go:171","msg":"trace[678871968] range","detail":"{range_begin:/registry/minions/10.0.0.78; range_end:; response_count:1; response_revision:509; }","duration":"118.550481ms","start":"2024-10-08T19:58:18.179721Z","end":"2024-10-08T19:58:18.298272Z","steps":["trace[678871968] 'agreement among raft nodes before linearized reading' (duration: 118.324457ms)"],"step_count":1} Oct 8 19:58:18.631013 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.630402Z","caller":"traceutil/trace.go:171","msg":"trace[1999079276] transaction","detail":"{read_only:false; number_of_response:1; response_revision:512; }","duration":"327.673056ms","start":"2024-10-08T19:58:18.302714Z","end":"2024-10-08T19:58:18.630387Z","steps":["trace[1999079276] 'process raft request' (duration: 327.643202ms)"],"step_count":1} Oct 8 19:58:18.631013 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.630426Z","caller":"traceutil/trace.go:171","msg":"trace[1978510735] transaction","detail":"{read_only:false; response_revision:511; number_of_response:1; }","duration":"330.445213ms","start":"2024-10-08T19:58:18.299951Z","end":"2024-10-08T19:58:18.630396Z","steps":["trace[1978510735] 'process raft request' (duration: 314.760177ms)","trace[1978510735] 'compare' (duration: 15.550756ms)"],"step_count":2} Oct 8 19:58:18.631013 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.630506Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:58:18.302698Z","time spent":"327.757495ms","remote":"10.0.0.67:34178","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":31,"response count":0,"response size":2272,"request content":"compare: success:> failure: >"} Oct 8 19:58:18.631013 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.630492Z","caller":"traceutil/trace.go:171","msg":"trace[2127112327] transaction","detail":"{read_only:false; response_revision:512; number_of_response:1; }","duration":"330.353758ms","start":"2024-10-08T19:58:18.300100Z","end":"2024-10-08T19:58:18.630454Z","steps":["trace[2127112327] 'process raft request' (duration: 330.238144ms)"],"step_count":1} Oct 8 19:58:18.631355 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.630538Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:58:18.299936Z","time spent":"330.547246ms","remote":"10.0.0.67:34184","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":3356,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 8 19:58:18.631355 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.630645Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:58:18.300052Z","time spent":"330.533115ms","remote":"10.0.0.67:34184","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":13709,"response count":0,"response size":40,"request content":"compare: success:> failure:<>"} Oct 8 19:58:18.657871 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.657526Z","caller":"traceutil/trace.go:171","msg":"trace[1173500013] transaction","detail":"{read_only:false; response_revision:513; number_of_response:1; }","duration":"108.710983ms","start":"2024-10-08T19:58:18.548798Z","end":"2024-10-08T19:58:18.657509Z","steps":["trace[1173500013] 'process raft request' (duration: 108.538262ms)"],"step_count":1} Oct 8 19:58:18.781708 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781038Z","caller":"traceutil/trace.go:171","msg":"trace[1854208310] transaction","detail":"{read_only:false; response_revision:514; number_of_response:1; }","duration":"148.093814ms","start":"2024-10-08T19:58:18.632917Z","end":"2024-10-08T19:58:18.781010Z","steps":["trace[1854208310] 'process raft request' (duration: 117.923169ms)","trace[1854208310] 'compare' (duration: 29.99158ms)"],"step_count":2} Oct 8 19:58:18.781708 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781106Z","caller":"traceutil/trace.go:171","msg":"trace[1551630869] linearizableReadLoop","detail":"{readStateIndex:534; appliedIndex:528; }","duration":"110.271191ms","start":"2024-10-08T19:58:18.670820Z","end":"2024-10-08T19:58:18.781091Z","steps":["trace[1551630869] 'read index received' (duration: 80.088114ms)","trace[1551630869] 'applied index is now lower than readState.Index' (duration: 30.182577ms)"],"step_count":2} Oct 8 19:58:18.781708 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781129Z","caller":"traceutil/trace.go:171","msg":"trace[239969660] transaction","detail":"{read_only:false; response_revision:516; number_of_response:1; }","duration":"146.266318ms","start":"2024-10-08T19:58:18.634838Z","end":"2024-10-08T19:58:18.781104Z","steps":["trace[239969660] 'process raft request' (duration: 146.161462ms)"],"step_count":1} Oct 8 19:58:18.781708 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781106Z","caller":"traceutil/trace.go:171","msg":"trace[633533220] transaction","detail":"{read_only:false; response_revision:518; number_of_response:1; }","duration":"140.99907ms","start":"2024-10-08T19:58:18.640097Z","end":"2024-10-08T19:58:18.781096Z","steps":["trace[633533220] 'process raft request' (duration: 140.950571ms)"],"step_count":1} Oct 8 19:58:18.782027 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781240Z","caller":"traceutil/trace.go:171","msg":"trace[9022285] transaction","detail":"{read_only:false; response_revision:517; number_of_response:1; }","duration":"145.710314ms","start":"2024-10-08T19:58:18.635524Z","end":"2024-10-08T19:58:18.781234Z","steps":["trace[9022285] 'process raft request' (duration: 145.501245ms)"],"step_count":1} Oct 8 19:58:18.782027 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.781252Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"110.420391ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/default/10.0.0.78.17fc928e7fd79b85\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:18.782027 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781265Z","caller":"traceutil/trace.go:171","msg":"trace[1024434153] transaction","detail":"{read_only:false; response_revision:515; number_of_response:1; }","duration":"146.456113ms","start":"2024-10-08T19:58:18.634802Z","end":"2024-10-08T19:58:18.781259Z","steps":["trace[1024434153] 'process raft request' (duration: 146.142908ms)"],"step_count":1} Oct 8 19:58:18.782027 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781286Z","caller":"traceutil/trace.go:171","msg":"trace[1900755029] transaction","detail":"{read_only:false; response_revision:519; number_of_response:1; }","duration":"120.731976ms","start":"2024-10-08T19:58:18.660546Z","end":"2024-10-08T19:58:18.781278Z","steps":["trace[1900755029] 'process raft request' (duration: 120.523686ms)"],"step_count":1} Oct 8 19:58:18.782027 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.781296Z","caller":"traceutil/trace.go:171","msg":"trace[46474075] range","detail":"{range_begin:/registry/events/default/10.0.0.78.17fc928e7fd79b85; range_end:; response_count:0; response_revision:519; }","duration":"110.45399ms","start":"2024-10-08T19:58:18.670816Z","end":"2024-10-08T19:58:18.781270Z","steps":["trace[46474075] 'agreement among raft nodes before linearized reading' (duration: 110.397153ms)"],"step_count":1} Oct 8 19:58:18.820339 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.819923Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"126.912446ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/10.0.0.78\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:18.820339 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.820000Z","caller":"traceutil/trace.go:171","msg":"trace[1910940802] range","detail":"{range_begin:/registry/csinodes/10.0.0.78; range_end:; response_count:0; response_revision:520; }","duration":"126.992261ms","start":"2024-10-08T19:58:18.692993Z","end":"2024-10-08T19:58:18.819985Z","steps":["trace[1910940802] 'agreement among raft nodes before linearized reading' (duration: 126.786913ms)"],"step_count":1} Oct 8 19:58:18.820339 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:18.819923Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"142.952501ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/10.0.0.78\" ","response":"range_response_count:1 size:2453"} Oct 8 19:58:18.820339 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:18.820095Z","caller":"traceutil/trace.go:171","msg":"trace[1622112057] range","detail":"{range_begin:/registry/minions/10.0.0.78; range_end:; response_count:1; response_revision:520; }","duration":"143.180486ms","start":"2024-10-08T19:58:18.676906Z","end":"2024-10-08T19:58:18.820087Z","steps":["trace[1622112057] 'agreement among raft nodes before linearized reading' (duration: 142.92719ms)"],"step_count":1} Oct 8 19:58:19.842489 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:19.842101Z","caller":"traceutil/trace.go:171","msg":"trace[1291394736] transaction","detail":"{read_only:false; response_revision:530; number_of_response:1; }","duration":"146.197009ms","start":"2024-10-08T19:58:19.695889Z","end":"2024-10-08T19:58:19.842086Z","steps":["trace[1291394736] 'process raft request' (duration: 139.261344ms)"],"step_count":1} Oct 8 19:58:22.034784 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:22.034218Z","caller":"traceutil/trace.go:171","msg":"trace[1884880905] transaction","detail":"{read_only:false; response_revision:541; number_of_response:1; }","duration":"117.653606ms","start":"2024-10-08T19:58:21.916546Z","end":"2024-10-08T19:58:22.034200Z","steps":["trace[1884880905] 'process raft request' (duration: 38.719993ms)","trace[1884880905] 'compare' (duration: 78.838655ms)"],"step_count":2} Oct 8 19:58:22.709842 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:22.709500Z","caller":"traceutil/trace.go:171","msg":"trace[518291889] transaction","detail":"{read_only:false; response_revision:544; number_of_response:1; }","duration":"114.43658ms","start":"2024-10-08T19:58:22.595046Z","end":"2024-10-08T19:58:22.709482Z","steps":["trace[518291889] 'process raft request' (duration: 104.877653ms)"],"step_count":1} Oct 8 19:58:22.969388 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:22.968291Z","caller":"traceutil/trace.go:171","msg":"trace[2072782543] transaction","detail":"{read_only:false; response_revision:545; number_of_response:1; }","duration":"156.992088ms","start":"2024-10-08T19:58:22.811281Z","end":"2024-10-08T19:58:22.968273Z","steps":["trace[2072782543] 'process raft request' (duration: 156.696777ms)"],"step_count":1} Oct 8 19:58:22.977973 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:22.977356Z","caller":"traceutil/trace.go:171","msg":"trace[1570399622] transaction","detail":"{read_only:false; response_revision:546; number_of_response:1; }","duration":"123.688757ms","start":"2024-10-08T19:58:22.853648Z","end":"2024-10-08T19:58:22.977337Z","steps":["trace[1570399622] 'process raft request' (duration: 123.575323ms)"],"step_count":1} Oct 8 19:58:27.857550 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:27.857162Z","caller":"traceutil/trace.go:171","msg":"trace[1751604765] transaction","detail":"{read_only:false; response_revision:575; number_of_response:1; }","duration":"106.791184ms","start":"2024-10-08T19:58:27.750351Z","end":"2024-10-08T19:58:27.857142Z","steps":["trace[1751604765] 'process raft request' (duration: 106.665044ms)"],"step_count":1} Oct 8 19:58:27.997532 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:27.997071Z","caller":"traceutil/trace.go:171","msg":"trace[1367789295] transaction","detail":"{read_only:false; response_revision:577; number_of_response:1; }","duration":"100.215893ms","start":"2024-10-08T19:58:27.896835Z","end":"2024-10-08T19:58:27.997051Z","steps":["trace[1367789295] 'process raft request' (duration: 17.325328ms)","trace[1367789295] 'compare' (duration: 82.783684ms)"],"step_count":2} Oct 8 19:58:28.011014 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:28.010628Z","caller":"traceutil/trace.go:171","msg":"trace[1547248844] transaction","detail":"{read_only:false; response_revision:578; number_of_response:1; }","duration":"105.577505ms","start":"2024-10-08T19:58:27.905029Z","end":"2024-10-08T19:58:28.010606Z","steps":["trace[1547248844] 'process raft request' (duration: 105.409298ms)"],"step_count":1} Oct 8 19:58:29.078241 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077532Z","caller":"traceutil/trace.go:171","msg":"trace[1928116147] transaction","detail":"{read_only:false; response_revision:584; number_of_response:1; }","duration":"190.568306ms","start":"2024-10-08T19:58:28.886944Z","end":"2024-10-08T19:58:29.077512Z","steps":["trace[1928116147] 'process raft request' (duration: 104.885966ms)","trace[1928116147] 'compare' (duration: 85.502397ms)"],"step_count":2} Oct 8 19:58:29.078241 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077718Z","caller":"traceutil/trace.go:171","msg":"trace[132840005] linearizableReadLoop","detail":"{readStateIndex:601; appliedIndex:599; }","duration":"185.38648ms","start":"2024-10-08T19:58:28.892322Z","end":"2024-10-08T19:58:29.077708Z","steps":["trace[132840005] 'read index received' (duration: 9.462313ms)","trace[132840005] 'applied index is now lower than readState.Index' (duration: 175.923336ms)"],"step_count":2} Oct 8 19:58:29.078241 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077730Z","caller":"traceutil/trace.go:171","msg":"trace[369070920] transaction","detail":"{read_only:false; response_revision:585; number_of_response:1; }","duration":"178.900467ms","start":"2024-10-08T19:58:28.898816Z","end":"2024-10-08T19:58:29.077717Z","steps":["trace[369070920] 'process raft request' (duration: 178.649308ms)"],"step_count":1} Oct 8 19:58:29.078241 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077792Z","caller":"traceutil/trace.go:171","msg":"trace[1478206926] transaction","detail":"{read_only:false; response_revision:586; number_of_response:1; }","duration":"173.762023ms","start":"2024-10-08T19:58:28.904026Z","end":"2024-10-08T19:58:29.077788Z","steps":["trace[1478206926] 'process raft request' (duration: 173.654598ms)"],"step_count":1} Oct 8 19:58:29.078241 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:29.077815Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"185.483984ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:29.078847 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077888Z","caller":"traceutil/trace.go:171","msg":"trace[1916609186] transaction","detail":"{read_only:false; response_revision:587; number_of_response:1; }","duration":"149.830533ms","start":"2024-10-08T19:58:28.928050Z","end":"2024-10-08T19:58:29.077881Z","steps":["trace[1916609186] 'process raft request' (duration: 149.721206ms)"],"step_count":1} Oct 8 19:58:29.078847 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.077893Z","caller":"traceutil/trace.go:171","msg":"trace[141771475] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:586; }","duration":"185.585922ms","start":"2024-10-08T19:58:28.892289Z","end":"2024-10-08T19:58:29.077875Z","steps":["trace[141771475] 'agreement among raft nodes before linearized reading' (duration: 185.476434ms)"],"step_count":1} Oct 8 19:58:29.139987 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.139608Z","caller":"traceutil/trace.go:171","msg":"trace[642876926] transaction","detail":"{read_only:false; response_revision:588; number_of_response:1; }","duration":"136.453065ms","start":"2024-10-08T19:58:29.003104Z","end":"2024-10-08T19:58:29.139557Z","steps":["trace[642876926] 'process raft request' (duration: 136.293904ms)"],"step_count":1} Oct 8 19:58:29.139987 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:29.139620Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"129.898951ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:492"} Oct 8 19:58:29.139987 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.139712Z","caller":"traceutil/trace.go:171","msg":"trace[150028469] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:588; }","duration":"130.012271ms","start":"2024-10-08T19:58:29.009690Z","end":"2024-10-08T19:58:29.139703Z","steps":["trace[150028469] 'agreement among raft nodes before linearized reading' (duration: 129.822178ms)"],"step_count":1} Oct 8 19:58:29.893465 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:29.892998Z","caller":"traceutil/trace.go:171","msg":"trace[45415224] transaction","detail":"{read_only:false; response_revision:593; number_of_response:1; }","duration":"249.254119ms","start":"2024-10-08T19:58:29.643725Z","end":"2024-10-08T19:58:29.892979Z","steps":["trace[45415224] 'process raft request' (duration: 249.019058ms)"],"step_count":1} Oct 8 19:58:33.173662 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:33.173314Z","caller":"traceutil/trace.go:171","msg":"trace[1298245726] transaction","detail":"{read_only:false; response_revision:615; number_of_response:1; }","duration":"131.169239ms","start":"2024-10-08T19:58:33.042127Z","end":"2024-10-08T19:58:33.173296Z","steps":["trace[1298245726] 'process raft request' (duration: 72.701105ms)","trace[1298245726] 'compare' (duration: 58.386861ms)"],"step_count":2} Oct 8 19:58:33.357848 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:33.357382Z","caller":"traceutil/trace.go:171","msg":"trace[1561592495] transaction","detail":"{read_only:false; response_revision:617; number_of_response:1; }","duration":"120.203069ms","start":"2024-10-08T19:58:33.237156Z","end":"2024-10-08T19:58:33.357359Z","steps":["trace[1561592495] 'process raft request' (duration: 55.524151ms)","trace[1561592495] 'compare' (duration: 64.591247ms)"],"step_count":2} Oct 8 19:58:33.386610 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:33.386139Z","caller":"traceutil/trace.go:171","msg":"trace[2076381630] transaction","detail":"{read_only:false; response_revision:619; number_of_response:1; }","duration":"108.060433ms","start":"2024-10-08T19:58:33.278062Z","end":"2024-10-08T19:58:33.386122Z","steps":["trace[2076381630] 'process raft request' (duration: 108.029757ms)"],"step_count":1} Oct 8 19:58:33.386610 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:33.386182Z","caller":"traceutil/trace.go:171","msg":"trace[959064392] transaction","detail":"{read_only:false; response_revision:618; number_of_response:1; }","duration":"148.53683ms","start":"2024-10-08T19:58:33.237620Z","end":"2024-10-08T19:58:33.386157Z","steps":["trace[959064392] 'process raft request' (duration: 148.378378ms)"],"step_count":1} Oct 8 19:58:36.129918 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:36.129320Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.873312ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:29"} Oct 8 19:58:36.129918 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:36.129490Z","caller":"traceutil/trace.go:171","msg":"trace[1815902551] transaction","detail":"{read_only:false; response_revision:627; number_of_response:1; }","duration":"143.856132ms","start":"2024-10-08T19:58:35.985623Z","end":"2024-10-08T19:58:36.129479Z","steps":["trace[1815902551] 'process raft request' (duration: 143.783385ms)"],"step_count":1} Oct 8 19:58:38.078044 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.077434Z","caller":"traceutil/trace.go:171","msg":"trace[619388436] transaction","detail":"{read_only:false; response_revision:650; number_of_response:1; }","duration":"139.913009ms","start":"2024-10-08T19:58:37.937502Z","end":"2024-10-08T19:58:38.077415Z","steps":["trace[619388436] 'process raft request' (duration: 139.781988ms)"],"step_count":1} Oct 8 19:58:38.078044 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.077615Z","caller":"traceutil/trace.go:171","msg":"trace[2026355734] transaction","detail":"{read_only:false; response_revision:651; number_of_response:1; }","duration":"136.674464ms","start":"2024-10-08T19:58:37.940920Z","end":"2024-10-08T19:58:38.077594Z","steps":["trace[2026355734] 'process raft request' (duration: 136.446694ms)"],"step_count":1} Oct 8 19:58:38.078044 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.077676Z","caller":"traceutil/trace.go:171","msg":"trace[620962655] transaction","detail":"{read_only:false; response_revision:652; number_of_response:1; }","duration":"132.67949ms","start":"2024-10-08T19:58:37.944980Z","end":"2024-10-08T19:58:38.077659Z","steps":["trace[620962655] 'process raft request' (duration: 132.570677ms)"],"step_count":1} Oct 8 19:58:38.279125 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.276653Z","caller":"traceutil/trace.go:171","msg":"trace[2083819308] transaction","detail":"{read_only:false; response_revision:654; number_of_response:1; }","duration":"189.98117ms","start":"2024-10-08T19:58:38.086656Z","end":"2024-10-08T19:58:38.276637Z","steps":["trace[2083819308] 'process raft request' (duration: 152.614084ms)","trace[2083819308] 'compare' (duration: 37.216832ms)"],"step_count":2} Oct 8 19:58:38.279269 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.276727Z","caller":"traceutil/trace.go:171","msg":"trace[2080245573] transaction","detail":"{read_only:false; response_revision:655; number_of_response:1; }","duration":"188.059506ms","start":"2024-10-08T19:58:38.088658Z","end":"2024-10-08T19:58:38.276717Z","steps":["trace[2080245573] 'process raft request' (duration: 187.946937ms)"],"step_count":1} Oct 8 19:58:38.436135 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.435694Z","caller":"traceutil/trace.go:171","msg":"trace[1395131437] transaction","detail":"{read_only:false; response_revision:656; number_of_response:1; }","duration":"304.9112ms","start":"2024-10-08T19:58:38.130765Z","end":"2024-10-08T19:58:38.435676Z","steps":["trace[1395131437] 'process raft request' (duration: 266.965297ms)","trace[1395131437] 'compare' (duration: 37.842917ms)"],"step_count":2} Oct 8 19:58:38.436135 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.435758Z","caller":"traceutil/trace.go:171","msg":"trace[1043589256] transaction","detail":"{read_only:false; response_revision:657; number_of_response:1; }","duration":"284.055802ms","start":"2024-10-08T19:58:38.151692Z","end":"2024-10-08T19:58:38.435747Z","steps":["trace[1043589256] 'process raft request' (duration: 283.953006ms)"],"step_count":1} Oct 8 19:58:38.436135 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:38.435789Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2024-10-08T19:58:38.130756Z","time spent":"304.986122ms","remote":"10.0.0.67:34278","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} Oct 8 19:58:38.945286 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:38.944867Z","caller":"traceutil/trace.go:171","msg":"trace[362385970] transaction","detail":"{read_only:false; response_revision:661; number_of_response:1; }","duration":"167.293756ms","start":"2024-10-08T19:58:38.777546Z","end":"2024-10-08T19:58:38.944840Z","steps":["trace[362385970] 'process raft request' (duration: 113.516569ms)","trace[362385970] 'compare' (duration: 53.547175ms)"],"step_count":2} Oct 8 19:58:39.092177 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:39.091789Z","caller":"traceutil/trace.go:171","msg":"trace[1173096710] transaction","detail":"{read_only:false; response_revision:662; number_of_response:1; }","duration":"145.311053ms","start":"2024-10-08T19:58:38.946455Z","end":"2024-10-08T19:58:39.091766Z","steps":["trace[1173096710] 'process raft request' (duration: 107.052224ms)","trace[1173096710] 'compare' (duration: 38.148913ms)"],"step_count":2} Oct 8 19:58:41.004225 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:41.003847Z","caller":"traceutil/trace.go:171","msg":"trace[430181227] transaction","detail":"{read_only:false; response_revision:679; number_of_response:1; }","duration":"214.954261ms","start":"2024-10-08T19:58:40.788875Z","end":"2024-10-08T19:58:41.003829Z","steps":["trace[430181227] 'process raft request' (duration: 214.909274ms)"],"step_count":1} Oct 8 19:58:41.004225 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:41.003907Z","caller":"traceutil/trace.go:171","msg":"trace[979597078] transaction","detail":"{read_only:false; response_revision:678; number_of_response:1; }","duration":"221.524028ms","start":"2024-10-08T19:58:40.782359Z","end":"2024-10-08T19:58:41.003883Z","steps":["trace[979597078] 'process raft request' (duration: 200.343633ms)","trace[979597078] 'compare' (duration: 20.976897ms)"],"step_count":2} Oct 8 19:58:42.026604 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:42.025826Z","caller":"traceutil/trace.go:171","msg":"trace[1052384327] linearizableReadLoop","detail":"{readStateIndex:706; appliedIndex:704; }","duration":"143.826294ms","start":"2024-10-08T19:58:41.881979Z","end":"2024-10-08T19:58:42.025806Z","steps":["trace[1052384327] 'read index received' (duration: 1.608408ms)","trace[1052384327] 'applied index is now lower than readState.Index' (duration: 142.217266ms)"],"step_count":2} Oct 8 19:58:42.026604 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:42.025828Z","caller":"traceutil/trace.go:171","msg":"trace[805510530] transaction","detail":"{read_only:false; response_revision:686; number_of_response:1; }","duration":"200.66187ms","start":"2024-10-08T19:58:41.825151Z","end":"2024-10-08T19:58:42.025813Z","steps":["trace[805510530] 'process raft request' (duration: 172.130977ms)","trace[805510530] 'compare' (duration: 28.412993ms)"],"step_count":2} Oct 8 19:58:42.026604 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:42.025920Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"143.927474ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:42.026604 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:42.025948Z","caller":"traceutil/trace.go:171","msg":"trace[279645593] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:686; }","duration":"143.964792ms","start":"2024-10-08T19:58:41.881974Z","end":"2024-10-08T19:58:42.025939Z","steps":["trace[279645593] 'agreement among raft nodes before linearized reading' (duration: 143.896635ms)"],"step_count":1} Oct 8 19:58:42.897672 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:42.897299Z","caller":"traceutil/trace.go:171","msg":"trace[478158986] transaction","detail":"{read_only:false; response_revision:690; number_of_response:1; }","duration":"114.303428ms","start":"2024-10-08T19:58:42.782980Z","end":"2024-10-08T19:58:42.897284Z","steps":["trace[478158986] 'process raft request' (duration: 114.190644ms)"],"step_count":1} Oct 8 19:58:42.943876 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:42.943505Z","caller":"traceutil/trace.go:171","msg":"trace[178648025] transaction","detail":"{read_only:false; response_revision:691; number_of_response:1; }","duration":"150.425974ms","start":"2024-10-08T19:58:42.793059Z","end":"2024-10-08T19:58:42.943485Z","steps":["trace[178648025] 'process raft request' (duration: 150.276943ms)"],"step_count":1} Oct 8 19:58:43.019387 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:43.018993Z","caller":"traceutil/trace.go:171","msg":"trace[520771394] transaction","detail":"{read_only:false; response_revision:692; number_of_response:1; }","duration":"118.836326ms","start":"2024-10-08T19:58:42.900138Z","end":"2024-10-08T19:58:43.018975Z","steps":["trace[520771394] 'process raft request' (duration: 68.894982ms)","trace[520771394] 'compare' (duration: 49.847783ms)"],"step_count":2} Oct 8 19:58:48.193398 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:48.192954Z","caller":"traceutil/trace.go:171","msg":"trace[1247389866] transaction","detail":"{read_only:false; response_revision:730; number_of_response:1; }","duration":"184.143643ms","start":"2024-10-08T19:58:48.008791Z","end":"2024-10-08T19:58:48.192935Z","steps":["trace[1247389866] 'process raft request' (duration: 184.002863ms)"],"step_count":1} Oct 8 19:58:48.423776 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:48.423258Z","caller":"traceutil/trace.go:171","msg":"trace[124094211] transaction","detail":"{read_only:false; response_revision:732; number_of_response:1; }","duration":"165.707997ms","start":"2024-10-08T19:58:48.257529Z","end":"2024-10-08T19:58:48.423237Z","steps":["trace[124094211] 'process raft request' (duration: 100.741705ms)","trace[124094211] 'compare' (duration: 64.870262ms)"],"step_count":2} Oct 8 19:58:48.454628 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:48.454157Z","caller":"traceutil/trace.go:171","msg":"trace[2039219577] transaction","detail":"{read_only:false; response_revision:733; number_of_response:1; }","duration":"193.888298ms","start":"2024-10-08T19:58:48.260248Z","end":"2024-10-08T19:58:48.454136Z","steps":["trace[2039219577] 'process raft request' (duration: 193.768947ms)"],"step_count":1} Oct 8 19:58:58.983084 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:58:58.982705Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"102.588569ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 8 19:58:58.983084 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:58:58.982796Z","caller":"traceutil/trace.go:171","msg":"trace[451848903] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:787; }","duration":"102.7208ms","start":"2024-10-08T19:58:58.880057Z","end":"2024-10-08T19:58:58.982778Z","steps":["trace[451848903] 'range keys from in-memory index tree' (duration: 102.533509ms)"],"step_count":1} Oct 8 19:59:12.015153 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:59:12.014799Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"147.087873ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 8 19:59:12.015153 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:12.014875Z","caller":"traceutil/trace.go:171","msg":"trace[985375046] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:837; }","duration":"147.200976ms","start":"2024-10-08T19:59:11.867659Z","end":"2024-10-08T19:59:12.014860Z","steps":["trace[985375046] 'range keys from in-memory index tree' (duration: 147.011396ms)"],"step_count":1} Oct 8 19:59:12.015153 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:59:12.014795Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"130.404751ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/roles/\" range_end:\"/registry/roles0\" count_only:true ","response":"range_response_count:0 size:7"} Oct 8 19:59:12.015778 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:12.014947Z","caller":"traceutil/trace.go:171","msg":"trace[1494964778] range","detail":"{range_begin:/registry/roles/; range_end:/registry/roles0; response_count:0; response_revision:837; }","duration":"130.604086ms","start":"2024-10-08T19:59:11.884337Z","end":"2024-10-08T19:59:12.014941Z","steps":["trace[1494964778] 'count revisions from in-memory index tree' (duration: 130.343717ms)"],"step_count":1} Oct 8 19:59:32.455416 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:32.454800Z","caller":"traceutil/trace.go:171","msg":"trace[540633594] transaction","detail":"{read_only:false; response_revision:1034; number_of_response:1; }","duration":"196.87301ms","start":"2024-10-08T19:59:32.257908Z","end":"2024-10-08T19:59:32.454781Z","steps":["trace[540633594] 'process raft request' (duration: 100.75197ms)","trace[540633594] 'compare' (duration: 96.035653ms)"],"step_count":2} Oct 8 19:59:32.456245 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:32.455916Z","caller":"traceutil/trace.go:171","msg":"trace[1747534049] transaction","detail":"{read_only:false; response_revision:1035; number_of_response:1; }","duration":"196.740638ms","start":"2024-10-08T19:59:32.259148Z","end":"2024-10-08T19:59:32.455889Z","steps":["trace[1747534049] 'process raft request' (duration: 196.537973ms)"],"step_count":1} Oct 8 19:59:35.996915 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:35.996415Z","caller":"traceutil/trace.go:171","msg":"trace[22712261] linearizableReadLoop","detail":"{readStateIndex:1083; appliedIndex:1082; }","duration":"136.290544ms","start":"2024-10-08T19:59:35.860103Z","end":"2024-10-08T19:59:35.996394Z","steps":["trace[22712261] 'read index received' (duration: 136.148584ms)","trace[22712261] 'applied index is now lower than readState.Index' (duration: 141.328µs)"],"step_count":2} Oct 8 19:59:35.996915 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:35.996483Z","caller":"traceutil/trace.go:171","msg":"trace[871560224] transaction","detail":"{read_only:false; response_revision:1048; number_of_response:1; }","duration":"192.384514ms","start":"2024-10-08T19:59:35.804085Z","end":"2024-10-08T19:59:35.996469Z","steps":["trace[871560224] 'process raft request' (duration: 192.180835ms)"],"step_count":1} Oct 8 19:59:35.996915 etcd-wrapper[1634]: {"level":"warn","ts":"2024-10-08T19:59:35.996539Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"136.423378ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} Oct 8 19:59:35.996915 etcd-wrapper[1634]: {"level":"info","ts":"2024-10-08T19:59:35.996591Z","caller":"traceutil/trace.go:171","msg":"trace[1773316414] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1048; }","duration":"136.506171ms","start":"2024-10-08T19:59:35.860077Z","end":"2024-10-08T19:59:35.996583Z","steps":["trace[1773316414] 'agreement among raft nodes before linearized reading' (duration: 136.432673ms)"],"step_count":1}