[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 491739086 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001009] APIC: Switch to symmetric I/O mode setup [ 0.002330] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006644] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007017] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009004] pid_max: default: 32768 minimum: 301 [ 0.010118] LSM: Security Framework initializing [ 0.011045] Yama: becoming mindful. [ 0.012031] SELinux: Initializing. [ 0.013059] *** VALIDATE selinux *** [ 0.020778] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024759] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025146] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026108] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027112] *** VALIDATE tmpfs *** [ 0.028436] *** VALIDATE proc *** [ 0.029255] *** VALIDATE cgroup *** [ 0.030010] *** VALIDATE cgroup2 *** [ 0.031274] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.033047] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.034008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.035041] Spectre V2 : User space: Vulnerable [ 0.036009] Speculative Store Bypass: Vulnerable [ 0.039292] debug: unmapping init [mem 0xffffffff93659000-0xffffffff93660fff] [ 0.042000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042695] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043019] ... version: 2 [ 0.044010] ... bit width: 48 [ 0.045012] ... generic registers: 4 [ 0.046012] ... value mask: 0000ffffffffffff [ 0.047016] ... max period: 00007fffffffffff [ 0.048015] ... fixed-purpose events: 3 [ 0.049010] ... event mask: 000000070000000f [ 0.050287] rcu: Hierarchical SRCU implementation. [ 0.052376] smp: Bringing up secondary CPUs ... [ 0.053571] x86: Booting SMP configuration: [ 0.054023] .... node #0, CPUs: #1 #2 #3 [ 0.057256] smp: Brought up 1 node, 4 CPUs [ 0.059011] smpboot: Max logical packages: 1 [ 0.060020] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.132798] node 0 deferred pages initialised in 69ms [ 0.136101] devtmpfs: initialized [ 0.137268] x86/mm: Memory block size: 128MB [ 0.140567] gcov: version magic: 0x41383552 [ 0.143281] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.147102] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.149307] pinctrl core: initialized pinctrl subsystem [ 0.152175] [ 0.152750] ************************************************************* [ 0.155012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.156008] ** ** [ 0.158011] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.160010] ** ** [ 0.162012] ** This means that this kernel is built to expose internal ** [ 0.164012] ** IOMMU data structures, which may compromise security on ** [ 0.166013] ** your system. ** [ 0.168011] ** ** [ 0.169009] ** If you see this message and you are not debugging the ** [ 0.171019] ** kernel, report this immediately to your vendor! ** [ 0.173012] ** ** [ 0.175011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.177012] ************************************************************* [ 0.180255] NET: Registered protocol family 16 [ 0.182449] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.185063] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.188055] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.191088] cpuidle: using governor menu [ 0.192723] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.194655] PCI: Using configuration type 1 for base access [ 0.196115] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.205048] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.206041] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.207163] cryptd: max_cpu_qlen set to 1000 [ 0.211315] ACPI: Added _OSI(Module Device) [ 0.212015] ACPI: Added _OSI(Processor Device) [ 0.213009] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.214000] ACPI: Added _OSI(Processor Aggregator Device) [ 0.220000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.223320] ACPI: Interpreter enabled [ 0.224056] ACPI: PM: (supports S0 S3 S4 S5) [ 0.226010] ACPI: Using IOAPIC for interrupt routing [ 0.227084] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.229412] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.237983] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.240041] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.243020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.246084] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.252413] acpiphp: Slot [2] registered [ 0.254126] acpiphp: Slot [5] registered [ 0.255116] acpiphp: Slot [6] registered [ 0.257111] acpiphp: Slot [7] registered [ 0.258118] acpiphp: Slot [8] registered [ 0.259133] acpiphp: Slot [9] registered [ 0.261118] acpiphp: Slot [10] registered [ 0.263128] acpiphp: Slot [3] registered [ 0.264104] acpiphp: Slot [4] registered [ 0.266099] acpiphp: Slot [11] registered [ 0.267100] acpiphp: Slot [12] registered [ 0.269101] acpiphp: Slot [13] registered [ 0.270088] acpiphp: Slot [14] registered [ 0.271075] acpiphp: Slot [15] registered [ 0.273129] acpiphp: Slot [16] registered [ 0.274104] acpiphp: Slot [17] registered [ 0.276144] acpiphp: Slot [18] registered [ 0.278100] acpiphp: Slot [19] registered [ 0.279098] acpiphp: Slot [20] registered [ 0.281096] acpiphp: Slot [21] registered [ 0.282124] acpiphp: Slot [22] registered [ 0.284097] acpiphp: Slot [23] registered [ 0.285098] acpiphp: Slot [24] registered [ 0.286079] acpiphp: Slot [25] registered [ 0.288093] acpiphp: Slot [26] registered [ 0.289098] acpiphp: Slot [27] registered [ 0.290000] acpiphp: Slot [28] registered [ 0.290000] acpiphp: Slot [29] registered [ 0.291109] acpiphp: Slot [30] registered [ 0.293097] acpiphp: Slot [31] registered [ 0.294059] PCI host bridge to bus 0000:00 [ 0.295021] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.298023] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.300023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.303022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.306020] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.309035] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.311215] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.313885] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.316103] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.326016] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.332714] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.335019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.337011] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.339024] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.342450] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.344751] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.347040] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.349766] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.355014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.368796] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.373014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.378625] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.386016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.393015] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.411018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.425013] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.433014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.443015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.457017] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.475240] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.492015] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.503016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.524017] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.532531] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.541020] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.549016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.572018] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.583310] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.592012] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.598017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.625017] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.639903] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.649013] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.654013] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.667023] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.676423] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.679362] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.681372] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.684390] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.687189] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.692105] iommu: Default domain type: Passthrough [ 0.693392] SCSI subsystem initialized [ 0.695147] ACPI: bus type USB registered [ 0.696105] usbcore: registered new interface driver usbfs [ 0.698088] usbcore: registered new interface driver hub [ 0.699073] usbcore: registered new device driver usb [ 0.701155] pps_core: LinuxPPS API ver. 1 registered [ 0.702016] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.705047] PTP clock support registered [ 0.707222] EDAC MC: Ver: 3.0.0 [ 0.708132] PCI: Using ACPI for IRQ routing [ 0.709816] NetLabel: Initializing [ 0.711009] NetLabel: domain hash size = 128 [ 0.712009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.714080] NetLabel: unlabeled traffic allowed by default [ 0.716280] vgaarb: loaded [ 0.718253] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.720015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.729000] clocksource: Switched to clocksource kvm-clock [ 0.838137] VFS: Disk quotas dquot_6.6.0 [ 0.839747] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.842167] *** VALIDATE ramfs *** [ 0.843107] *** VALIDATE hugetlbfs *** [ 0.844303] pnp: PnP ACPI init [ 0.846784] pnp: PnP ACPI: found 6 devices [ 0.862863] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.866099] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.868222] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.870629] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.873210] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.875722] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.878718] NET: Registered protocol family 2 [ 0.881213] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.885684] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.889423] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.893593] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.896979] TCP: Hash tables configured (established 65536 bind 65536) [ 0.899899] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.903080] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.905783] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.908936] NET: Registered protocol family 1 [ 0.911805] RPC: Registered named UNIX socket transport module. [ 0.913795] RPC: Registered udp transport module. [ 0.915274] RPC: Registered tcp transport module. [ 0.916946] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.919103] NET: Registered protocol family 44 [ 0.920857] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.922662] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.924657] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.926766] PCI: CLS 0 bytes, default 64 [ 0.928215] Unpacking initramfs... [ 2.355725] debug: unmapping init [mem 0xffff90a2fcc54000-0xffff90a2fffbffff] [ 2.359745] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.362159] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.365178] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.853260] Initialise system trusted keyrings [ 2.855596] Key type blacklist registered [ 2.860964] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.870856] zbud: loaded [ 2.874685] *** VALIDATE nfs *** [ 2.876481] *** VALIDATE nfs4 *** [ 2.878640] pstore: using deflate compression [ 2.883491] Platform Keyring initialized [ 2.992773] NET: Registered protocol family 38 [ 2.994704] Key type asymmetric registered [ 2.996317] Asymmetric key parser 'x509' registered [ 2.998293] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.001561] io scheduler mq-deadline registered [ 3.003125] io scheduler kyber registered [ 3.004635] io scheduler bfq registered [ 3.006464] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.009607] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.012419] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.015242] ACPI: Power Button [PWRF] [ 3.020881] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.027590] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.048949] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.059394] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.072919] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.105152] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.143626] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.149249] Non-volatile memory driver v1.3 [ 3.151201] Linux agpgart interface v0.103 [ 3.180787] virtio_blk virtio1: [vda] 145912 512-byte logical blocks (74.7 MB/71.2 MiB) [ 3.183245] vda: detected capacity change from 0 to 74706944 [ 3.198961] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.201744] vdb: detected capacity change from 0 to 1073741824 [ 3.214584] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.216874] vdc: detected capacity change from 0 to 2621440000 [ 3.230290] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.233311] vdd: detected capacity change from 0 to 2621440000 [ 3.246509] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.251527] vde: detected capacity change from 0 to 4294967296 [ 3.265511] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.268104] vdf: detected capacity change from 0 to 4294967296 [ 3.285507] libphy: Fixed MDIO Bus: probed [ 3.290319] usbcore: registered new interface driver usbserial_generic [ 3.292930] usbserial: USB Serial support registered for generic [ 3.295618] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.299812] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.301731] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.304074] mousedev: PS/2 mouse device common for all mice [ 3.306577] rtc_cmos 00:05: RTC can wake from S4 [ 3.308714] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.309858] rtc_cmos 00:05: registered as rtc0 [ 3.313156] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.316022] intel_pstate: CPU model not supported [ 3.319103] hid: raw HID events driver (C) Jiri Kosina [ 3.321262] usbcore: registered new interface driver usbhid [ 3.324148] usbhid: USB HID core driver [ 3.325683] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.326861] drop_monitor: Initializing network drop monitor service [ 3.332445] Initializing XFRM netlink socket [ 3.334698] NET: Registered protocol family 10 [ 3.336899] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.337949] Segment Routing with IPv6 [ 3.341829] NET: Registered protocol family 17 [ 3.344805] mpls_gso: MPLS GSO support [ 3.350622] RAS: Correctable Errors collector initialized. [ 3.353135] AVX version of gcm_enc/dec engaged. [ 3.354905] AES CTR mode by8 optimization enabled [ 3.429458] sched_clock: Marking stable (3429435063, 0)->(4339074305, -909639242) [ 3.433300] registered taskstats version 1 [ 3.435938] Loading compiled-in X.509 certificates [ 3.438340] zswap: loaded using pool lzo/zbud [ 3.465699] Key type big_key registered [ 3.479121] Key type encrypted registered [ 3.480791] ima: No TPM chip found, activating TPM-bypass! [ 3.483050] ima: Allocated hash algorithm: sha1 [ 3.484491] ima: No architecture policies found [ 3.486276] evm: Initialising EVM extended attributes: [ 3.487785] evm: security.selinux [ 3.488912] evm: security.ima [ 3.489808] evm: security.capability [ 3.490513] evm: HMAC attrs: 0x1 [ 3.492623] rtc_cmos 00:05: setting system clock to 2026-08-14 18:30:54 UTC (1786732254) [ 3.497664] debug: unmapping init [mem 0xffffffff94603000-0xffffffff947fffff] [ 3.500486] debug: unmapping init [mem 0xffffffff93382000-0xffffffff93658fff] [ 3.509133] Write protecting the kernel read-only data: 28672k [ 3.512747] debug: unmapping init [mem 0xffffffff91a03000-0xffffffff91bfffff] [ 3.515878] debug: unmapping init [mem 0xffffffff92314000-0xffffffff923fffff] [ 3.548736] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.556759] systemd[1]: Detected virtualization kvm. [ 3.558730] systemd[1]: Detected architecture x86-64. [ 3.560457] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.584458] systemd[1]: No hostname configured. [ 3.586184] systemd[1]: Set hostname to . [ 3.588499] random: systemd: uninitialized urandom read (16 bytes read) [ 3.590891] systemd[1]: Initializing machine ID from random generator. [ 3.634801] random: ln: uninitialized urandom read (6 bytes read) [ 3.717240] random: systemd: uninitialized urandom read (16 bytes read) [ 3.720771] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.725948] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.730663] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Timers. Starting Setup Virtual Console... [ OK ] Listening on udev Kernel Socket. Starting Journal Service... [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK ] Reached target Sockets. [ OK ] Reached target Swap. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Initrd Root Device. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.308926] device-mapper: uevent: version 1.0.3 [ 4.311544] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] [ 4.905994] random: fast init done Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.948898] virtio_net virtio0 ens2: renamed from eth0 [ 5.002602] scsi host0: ata_piix [ 5.013234] scsi host1: ata_piix [ 5.014456] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.016424] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.412378] dracut-initqueue[586]: RTNETLINK answers: File exists [ 10.001508] random: crng init done [ 10.002836] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.314796] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.413776] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.668721] SELinux: Disabled at runtime. [ 11.732539] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 11.741958] systemd[1]: Detected virtualization kvm. [ 11.743976] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.243455] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.246709] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.251480] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.255400] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.259181] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.266783] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.271604] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. Mounting POSIX Message Queue File System... Mounting Huge Pages File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-getty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Reached target rpc_pipefs.target. Mounting Kernel Debug File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... Starting Remount Root and Kernel File Systems... Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target Slices. [ 12.459520] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.707357] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.002109] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.047552] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.148342] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.167482] EDAC sbridge: Ver: 1.1.2 [ 14.935545] Key type dns_resolver registered [ 15.260047] NFS: Registering the id_resolver key type [ 15.261439] Key type id_resolver registered [ 15.262701] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started D-Bus System Message Bus. [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg653-server login: [ 33.702405] spl: loading out-of-tree module taints kernel. [ 36.341867] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 43.130581] Key type ._llcrypt registered [ 43.132104] Key type .llcrypt registered [ 43.255096] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_hostid [ 65.150614] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing load_modules_local [ 67.131938] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 67.151497] alg: No test for adler32 (adler32-zlib) [ 68.860256] Lustre: Lustre: Build Version: 2.17.56_2_gd9f03f2 [ 69.844828] LNet: Added LNI 192.168.206.153@tcp [8/256/0/180] [ 71.695736] Key type lgssc registered [ 73.839722] Lustre: Echo OBD driver; http://www.lustre.org/ [ 85.847467] vdc: vdc1 vdc9 [ 92.843073] hrtimer: interrupt took 4064561 ns [ 96.488588] vde: vde1 vde9 [ 108.334075] vdf: vdf1 vdf9 [ 127.855872] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing load_modules_local [ 136.594428] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 137.831343] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 138.119143] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 138.229291] Lustre: lustre-MDT0000: new disk, initializing [ 138.631277] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 138.697642] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 142.895396] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 147.829594] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 153.693125] Lustre: lustre-OST0000: new disk, initializing [ 153.696371] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 153.704625] Lustre: Skipped 1 previous similar message [ 153.792754] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 160.034246] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 160.050877] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 160.201606] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 160.226456] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 171.146635] Lustre: lustre-OST0001: new disk, initializing [ 171.152795] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 171.318440] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 176.888442] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 176.904679] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 177.179777] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 178.802961] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 192.105032] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 199.411343] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 205.692773] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing check_logdir /tmp/testlogs/ [ 212.825676] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing yml_node [ 216.489312] Lustre: DEBUG MARKER: Client: 2.17.56.2 [ 218.979198] Lustre: DEBUG MARKER: MDS: 2.17.56.2 [ 221.440909] Lustre: DEBUG MARKER: OSS: 2.17.56.2 [ 223.614308] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-dual ============----- Fri Aug 14 14:34:32 EDT 2026 [ 240.306794] Lustre: DEBUG MARKER: excepting tests: 14b 21b 21b [ 242.027855] Lustre: DEBUG MARKER: skipping tests SLOW=no: 21b [ 243.512629] Lustre: DEBUG MARKER: === replay-dual: start setup 14:34:52 (1786732492) === [ 249.774536] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing check_config_client /mnt/lustre [ 269.671990] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 273.985576] Lustre: 11220:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 278.077282] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 281.738547] Lustre: DEBUG MARKER: === replay-dual: finish setup 14:35:31 (1786732531) === [ 283.724342] Lustre: DEBUG MARKER: == replay-dual test 0a: expired recovery with lost client ========================================================== 14:35:33 (1786732533) [ 287.198638] LustreError: 11716:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 288.148158] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 292.846931] Lustre: Failing over lustre-MDT0000 [ 293.222186] Lustre: server umount lustre-MDT0000 complete [ 309.793224] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 310.147387] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 310.321384] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 310.736216] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732545/real 1786732545] req@ffff90a350f42a00 x1873524629234176/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732561 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 310.755165] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 314.931764] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 315.295147] Lustre: 3310:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732550/real 1786732550] req@ffff90a350f40a80 x1873524629234432/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732566 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 315.320820] Lustre: 3310:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 315.371828] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 320.483081] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732555/real 1786732555] req@ffff90a2443cbb80 x1873524629234944/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732571 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 320.507334] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 325.600755] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732560/real 1786732560] req@ffff90a24536bb80 x1873524629235328/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732576 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 325.647383] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 412.500188] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 412.507927] Lustre: 12313:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client d3eceb6e-24fa-43ea-a64d-d58c5e48d438@192.168.206.53@tcp [ 412.524933] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 412.574122] Lustre: 12313:0:(ldlm_lib.c:2950:target_recovery_thread()) too long recovery - read logs [ 412.582781] LustreError: dumping log to /tmp/lustre-log.1786732663.12313 [ 412.732931] Lustre: lustre-MDT0000: Recovery over after 1:42, of 2 clients 1 recovered and 1 was evicted. [ 412.805784] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:28 to 0x280000400:65) [ 412.807505] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:28 to 0x240000400:65) [ 435.033809] Lustre: DEBUG MARKER: == replay-dual test 0b: lost client during waiting for next transno ========================================================== 14:38:04 (1786732684) [ 438.379101] LustreError: 13076:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 439.303384] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 441.810626] Lustre: Failing over lustre-MDT0000 [ 442.306298] Lustre: server umount lustre-MDT0000 complete [ 459.745538] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732694/real 1786732694] req@ffff90a247c9d180 x1873524629272192/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732710 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 459.746297] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 459.765915] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 459.766037] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 459.766040] Lustre: Skipped 1 previous similar message [ 469.919931] Lustre: 3310:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732704/real 1786732704] req@ffff90a247c9fb80 x1873524629272832/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732720 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 469.945306] Lustre: 3310:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 470.460850] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 471.476060] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 475.222667] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 484.655059] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 484.659687] Lustre: Skipped 1 previous similar message [ 487.762725] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:53 [ 492.977744] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:48 [ 498.092920] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:43 [ 503.215065] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:38 [ 508.332750] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:33 [ 518.575278] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:22 [ 518.613082] Lustre: Skipped 1 previous similar message [ 539.059102] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:02 [ 539.081034] Lustre: Skipped 3 previous similar messages [ 541.509576] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 541.519711] Lustre: 13670:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client bad0063b-53a6-4c13-a325-14f376cc989b@ [ 541.536767] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 574.891994] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 1 evicted) to recover in 1:07 [ 574.908281] Lustre: Skipped 6 previous similar messages [ 641.463983] Lustre: lustre-MDT0000: Denying connection for new client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 1 evicted) to recover in 0:01 [ 641.483614] Lustre: Skipped 12 previous similar messages [ 642.500298] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 642.509504] Lustre: 13670:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 572644c7-a21d-4728-84e8-a6a79c49b9bc@192.168.206.53@tcp [ 642.533640] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 642.545931] Lustre: 13670:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 642.625521] Lustre: 13670:0:(ldlm_lib.c:2950:target_recovery_thread()) too long recovery - read logs [ 642.632265] LustreError: dumping log to /tmp/lustre-log.1786732893.13670 [ 642.730710] Lustre: lustre-MDT0000: Recovery over after 2:51, of 2 clients 0 recovered and 2 were evicted. [ 642.768956] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:67 to 0x240000400:97) [ 642.772058] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:28 to 0x280000400:97) [ 654.190371] Lustre: DEBUG MARKER: == replay-dual test 1: |X| simple create ================= 14:41:43 (1786732903) [ 657.345271] LustreError: 14430:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 658.147564] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 660.340044] Lustre: Failing over lustre-MDT0000 [ 660.681291] Lustre: server umount lustre-MDT0000 complete [ 678.533411] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 678.793467] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 678.804572] Lustre: Skipped 1 previous similar message [ 678.962633] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 679.121576] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 680.076885] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 680.520330] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 680.573042] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:129) [ 680.573547] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:129) [ 680.863183] Lustre: 3312:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732915/real 1786732915] req@ffff90a245da9500 x1873524629311744/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732931 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 680.891152] Lustre: 3312:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 683.638748] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 684.030387] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 684.046268] Lustre: Skipped 1 previous similar message [ 693.119711] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 694.639395] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 702.145753] Lustre: DEBUG MARKER: == replay-dual test 2: |X| mkdir adir ==================== 14:42:31 (1786732951) [ 704.949371] LustreError: 15973:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 705.796936] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 707.976883] Lustre: Failing over lustre-MDT0000 [ 708.640366] Lustre: server umount lustre-MDT0000 complete [ 725.986970] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786732960/real 1786732960] req@ffff90a2490a9500 x1873524629326848/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786732976 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 725.990819] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 726.003681] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 726.018356] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 726.039758] Lustre: Skipped 2 previous similar messages [ 736.679528] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 736.753091] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 741.278297] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 750.517787] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 750.635151] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 750.685888] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:161) [ 750.692829] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:161) [ 751.085434] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 751.091983] Lustre: Skipped 1 previous similar message [ 756.104318] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 757.526875] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 765.769920] Lustre: DEBUG MARKER: == replay-dual test 3: |X| mkdir adir, mkdir adir/bdir === 14:43:35 (1786733015) [ 768.395112] LustreError: 17524:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 769.159702] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 770.795544] Lustre: Failing over lustre-MDT0000 [ 771.025829] Lustre: server umount lustre-MDT0000 complete [ 787.935211] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 787.942819] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 787.944901] Lustre: Skipped 1 previous similar message [ 792.097029] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786733027/real 1786733027] req@ffff90a245647800 x1873524629343104/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786733043 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 792.143394] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 798.886544] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 798.992483] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 803.591695] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 811.956556] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 812.131905] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 812.187725] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:193) [ 812.192497] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:193) [ 813.048762] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 813.058786] Lustre: Skipped 1 previous similar message [ 817.819770] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 819.701043] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 827.734823] Lustre: DEBUG MARKER: == replay-dual test 4: |X| mkdir adir (-EEXIST), mkdir adir/bdir ========================================================== 14:44:37 (1786733077) [ 830.640961] LustreError: 19070:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 831.506356] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 833.637246] Lustre: Failing over lustre-MDT0000 [ 834.151028] Lustre: server umount lustre-MDT0000 complete [ 852.176059] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 852.555455] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 852.570033] Lustre: Skipped 1 previous similar message [ 852.811679] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 853.038352] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 853.207691] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 853.246429] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:225) [ 853.248306] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:225) [ 857.637512] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 858.087573] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 858.099467] Lustre: Skipped 1 previous similar message [ 867.979557] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 869.611595] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 879.052702] Lustre: DEBUG MARKER: == replay-dual test 5: open, unlink |X| close ============ 14:45:28 (1786733128) [ 882.152377] LustreError: 20612:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 882.989825] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 884.837046] Lustre: Failing over lustre-MDT0000 [ 885.184497] Lustre: server umount lustre-MDT0000 complete [ 901.738587] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 902.068541] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 902.078260] Lustre: Skipped 1 previous similar message [ 902.229555] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 902.237217] Lustre: Skipped 1 previous similar message [ 902.300869] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 904.146178] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 904.297383] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 904.343813] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:257) [ 904.344835] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:257) [ 905.812370] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 907.241597] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 907.245145] Lustre: Skipped 1 previous similar message [ 913.739239] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 914.928157] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 923.598342] Lustre: DEBUG MARKER: == replay-dual test 6: open1, open2, unlink |X| close1 [fail mds1] close2 ========================================================== 14:46:12 (1786733172) [ 927.314741] LustreError: 22147:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 928.457778] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 930.575051] Lustre: Failing over lustre-MDT0000 [ 930.995910] Lustre: server umount lustre-MDT0000 complete [ 948.006223] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786733183/real 1786733183] req@ffff90a37aa65500 x1873524629391104/t0(0) o400->MGC192.168.206.153@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786733199 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 948.033494] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 16 previous similar messages [ 948.046838] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 949.088412] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 958.241284] LustreError: 3308:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff90a3511bad80 x1873524629392896/t0(0) o250->MGC192.168.206.153@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 959.267175] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 960.128129] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 960.136835] Lustre: Skipped 1 previous similar message [ 961.462055] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 961.687097] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 961.755234] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:289) [ 961.776174] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:289) [ 964.616430] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 975.434439] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 977.150550] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 985.411938] Lustre: DEBUG MARKER: == replay-dual test 8: replay of resent request ========== 14:47:14 (1786733234) [ 989.233571] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 990.036849] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 990.038546] LustreError: 22712:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a37aa64e00 x1873524607381376/t38654705670(0) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:82/0 lens 512/448 e 0 to 0 dl 1786733252 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 1005.489554] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnecting [ 1005.509699] Lustre: 22823:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff90a24742a300 x1873524607381376/t38654705670(0) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:97/0 lens 512/2880 e 0 to 0 dl 1786733267 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 1008.034486] Lustre: Failing over lustre-MDT0000 [ 1008.201200] Lustre: server umount lustre-MDT0000 complete [ 1025.152544] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1025.578834] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1025.593865] Lustre: Skipped 2 previous similar messages [ 1025.842925] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1026.027030] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1026.298521] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1026.345698] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:321) [ 1026.345877] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:321) [ 1030.502973] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1031.147828] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1031.163133] Lustre: Skipped 1 previous similar message [ 1038.444628] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1039.843621] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1047.006924] Lustre: DEBUG MARKER: == replay-dual test 9: resending a replayed create ======= 14:48:16 (1786733296) [ 1050.794227] LustreError: 25366:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1050.798893] LustreError: 25366:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 1051.791496] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1055.047867] Lustre: Failing over lustre-MDT0000 [ 1055.381561] Lustre: server umount lustre-MDT0000 complete [ 1082.338910] LustreError: 3308:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff90a3510ae300 x1873524629428608/t0(0) o250->MGC192.168.206.153@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1082.930964] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1082.934927] Lustre: Skipped 2 previous similar messages [ 1083.001059] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1087.772045] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1097.717838] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 1097.728598] LustreError: 26021:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a2490a8700 x1873524607396352/t42949672966(42949672966) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:189/0 lens 520/448 e 0 to 0 dl 1786733359 ref 1 fl Complete:/204/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 1114.081830] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnected, waiting for 2 clients in recovery for 1:24 [ 1114.256098] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:353) [ 1114.261612] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:353) [ 1121.173980] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1123.086297] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1131.766324] Lustre: DEBUG MARKER: == replay-dual test 10: resending a replayed unlink ====== 14:49:41 (1786733381) [ 1135.873752] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1139.049559] Lustre: Failing over lustre-MDT0000 [ 1139.505382] Lustre: server umount lustre-MDT0000 complete [ 1156.727381] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1156.742241] LustreError: Skipped 1 previous similar message [ 1157.033840] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1157.047122] Lustre: Skipped 3 previous similar messages [ 1157.286488] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1159.111904] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1159.120693] Lustre: Skipped 1 previous similar message [ 1159.169513] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 1159.176147] LustreError: 27677:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a379257800 x1873524607411584/t47244640264(47244640264) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:251/0 lens 504/456 e 0 to 0 dl 1786733421 ref 1 fl Complete:/204/0 rc 0/0 job:'unlink.0' uid:0 gid:0 projid:4294967295 [ 1161.391836] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1162.226555] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1162.238892] Lustre: Skipped 3 previous similar messages [ 1174.493233] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnected, waiting for 2 clients in recovery for 1:25 [ 1174.600858] Lustre: lustre-MDT0000: Recovery over after 0:15, of 2 clients 2 recovered and 0 were evicted. [ 1174.609753] Lustre: Skipped 1 previous similar message [ 1174.710608] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:385) [ 1174.711138] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:385) [ 1182.700037] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1184.380641] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1193.790581] Lustre: DEBUG MARKER: == replay-dual test 11: both clients timeout during replay ========================================================== 14:50:43 (1786733443) [ 1196.693633] LustreError: 28699:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1196.700496] LustreError: 28699:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 1197.494854] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1200.296919] Lustre: Failing over lustre-MDT0000 [ 1200.725910] Lustre: server umount lustre-MDT0000 complete [ 1219.175055] Lustre: 3312:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786733454/real 1786733454] req@ffff90a37ab11500 x1873524629464192/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786733470 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1219.211806] Lustre: 3312:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 28 previous similar messages [ 1220.606521] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 1220.612322] LustreError: 29333:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a3779b9880 x1873524607424768/t51539607558(51539607558) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:312/0 lens 520/448 e 0 to 0 dl 1786733482 ref 1 fl Complete:/204/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 1222.409671] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1229.253494] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1236.938869] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnected, waiting for 2 clients in recovery for 1:24 [ 1237.087564] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:417) [ 1237.088285] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:417) [ 1239.250464] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 8 sec [ 1247.343899] Lustre: DEBUG MARKER: == replay-dual test 12: open resend timeout ============== 14:51:36 (1786733496) [ 1251.475352] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1254.763335] Lustre: Failing over lustre-MDT0000 [ 1255.260104] Lustre: server umount lustre-MDT0000 complete [ 1279.917891] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1283.266458] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:449) [ 1283.270251] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:449) [ 1292.675379] Lustre: DEBUG MARKER: == replay-dual test 13: close resend timeout ============= 14:52:21 (1786733541) [ 1297.683520] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1300.589643] Lustre: Failing over lustre-MDT0000 [ 1301.012211] Lustre: server umount lustre-MDT0000 complete [ 1320.033910] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1320.043283] Lustre: Skipped 2 previous similar messages [ 1321.950542] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 1324.894052] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1337.340133] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnected, waiting for 2 clients in recovery for 1:25 [ 1337.663436] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:99 to 0x280000400:481) [ 1337.664307] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:99 to 0x240000400:481) [ 1346.250682] Lustre: DEBUG MARKER: SKIP: replay-dual test_14b skipping ALWAYS excluded test 14b [ 1348.578715] Lustre: DEBUG MARKER: == replay-dual test 15a: timeout waiting for lost client during replay, 1 client completes ========================================================== 14:53:17 (1786733597) [ 1353.677747] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1356.981278] Lustre: Failing over lustre-MDT0000 [ 1357.489301] Lustre: server umount lustre-MDT0000 complete [ 1375.169657] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1375.173550] Lustre: Skipped 4 previous similar messages [ 1380.262527] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1453.500648] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1453.504667] Lustre: 33771:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 255cce6e-b6e5-4c64-8cfd-bd30a026ead4@ [ 1453.512800] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1454.390955] Lustre: lustre-MDT0000: Recovery over after 1:11, of 2 clients 1 recovered and 1 was evicted. [ 1454.396513] Lustre: Skipped 3 previous similar messages [ 1454.449722] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:494 to 0x240000400:513) [ 1454.454808] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:495 to 0x280000400:513) [ 1460.666651] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1462.028762] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1472.154536] Lustre: DEBUG MARKER: == replay-dual test 15c: remove multiple OST orphans ===== 14:55:21 (1786733721) [ 1475.278332] LustreError: 34756:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1475.291715] LustreError: 34756:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 1476.088225] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1593.056416] Lustre: Failing over lustre-MDT0000 [ 1593.595694] Lustre: server umount lustre-MDT0000 complete [ 1611.646618] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1611.654056] LustreError: Skipped 4 previous similar messages [ 1612.028230] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1612.053908] Lustre: Skipped 8 previous similar messages [ 1612.371391] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1612.377084] Lustre: Skipped 1 previous similar message [ 1617.290221] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1617.393289] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1617.400593] Lustre: Skipped 9 previous similar messages [ 1619.379810] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1619.385496] Lustre: Skipped 4 previous similar messages [ 1689.500444] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1689.512577] Lustre: 35471:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client f46ad7ee-cd7c-4cf0-9462-c756b09de2db@ [ 1689.531415] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1689.700488] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:494 to 0x240000400:1537) [ 1689.702077] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:495 to 0x280000400:1537) [ 1696.125110] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1697.473297] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1706.159860] Lustre: DEBUG MARKER: == replay-dual test 16: fail MDS during recovery (3571) == 14:59:15 (1786733955) [ 1709.582115] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1712.184201] Lustre: Failing over lustre-MDT0000 [ 1712.530632] Lustre: server umount lustre-MDT0000 complete [ 1733.682848] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1735.647149] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786733970/real 1786733970] req@ffff90a247c9a680 x1873524629598848/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786733986 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1735.677743] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 34 previous similar messages [ 1757.787039] Lustre: Failing over lustre-MDT0000 [ 1757.814792] LustreError: 37522:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 1757.823214] Lustre: 37046:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1757.829718] Lustre: 37046:0:(ldlm_lib.c:1913:abort_req_replay_queue()) @@@ aborted: req@ffff90a34880ea00 x1873524609836160/t0(73014444037) o101->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:91/0 lens 592/0 e 2 to 0 dl 1786734016 ref 1 fl Complete:/604/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 1757.845761] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 1757.861523] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.53@tcp (stopping) [ 1758.352375] Lustre: server umount lustre-MDT0000 complete [ 1778.891776] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1848.500135] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1848.508249] Lustre: 37973:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 40ba15ad-e2af-4202-bb7c-5e4ee0a12f8e@ [ 1848.527391] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1849.520235] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1551 to 0x280000400:1569) [ 1849.521874] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1550 to 0x240000400:1569) [ 1855.223836] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1856.909293] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1867.023741] Lustre: DEBUG MARKER: == replay-dual test 17: fail OST during recovery (3571) == 15:01:56 (1786734116) [ 1871.642679] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 1873.530822] Lustre: Failing over lustre-OST0000 [ 1873.630155] Lustre: server umount lustre-OST0000 complete [ 1875.429020] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 1881.007739] LustreError: 6598:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1881.024015] LustreError: 6598:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 4 previous similar messages [ 1882.595764] LustreError: 38639:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1886.146722] LustreError: 6598:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1890.209111] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1890.212031] Lustre: Skipped 3 previous similar messages [ 1895.406510] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 1919.172069] Lustre: Failing over lustre-OST0000 [ 1919.188845] LustreError: 40103:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 1919.197775] Lustre: 39536:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1919.205605] Lustre: 39536:0:(ldlm_lib.c:2403:target_recovery_overseer()) Skipped 2 previous similar messages [ 1919.212339] LustreError: 39536:0:(ofd_obd.c:1324:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 1919.293653] Lustre: server umount lustre-OST0000 complete [ 1931.753684] LustreError: 38639:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1931.785958] LustreError: 38639:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 1943.069614] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2007.500150] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 2007.504965] Lustre: 40518:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client af0d77a0-096d-4b9d-94a4-b3d9a960f33a@ [ 2007.518842] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 2007.614670] Lustre: lustre-OST0000: Recovery over after 1:10, of 3 clients 2 recovered and 1 was evicted. [ 2007.619275] Lustre: Skipped 4 previous similar messages [ 2014.354615] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 2016.309767] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 2025.495459] Lustre: DEBUG MARKER: == replay-dual test 18: ldlm_handle_enqueue succeeds on evicted export (3822) ========================================================== 15:04:34 (1786734274) [ 2029.260626] LustreError: 38339:0:(ldlm_lockd.c:1361:ldlm_handle_enqueue()) cfs_fail_timeout id 30b sleeping for 40000ms [ 2069.343115] LustreError: 38339:0:(ldlm_lockd.c:1361:ldlm_handle_enqueue()) cfs_fail_timeout id 30b awake [ 2081.652729] Lustre: DEBUG MARKER: == replay-dual test 19: resend of open request =========== 15:05:30 (1786734330) [ 2084.916380] LustreError: 42063:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2084.921904] LustreError: 42063:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 2085.872370] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2087.032597] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 2087.038418] LustreError: 41619:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a24cd38a80 x1873524609939072/t0(0) o101->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:494/0 lens 576/688 e 0 to 0 dl 1786734419 ref 1 fl Interpret:/600/0 rc 0/0 job:'createmany.0' uid:0 gid:0 projid:0 [ 2172.363711] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnecting [ 2176.115428] Lustre: Failing over lustre-MDT0000 [ 2176.593281] Lustre: server umount lustre-MDT0000 complete [ 2193.156443] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2193.162645] LustreError: Skipped 2 previous similar messages [ 2193.515988] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2193.534728] Lustre: Skipped 7 previous similar messages [ 2193.765445] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2193.774615] Lustre: Skipped 4 previous similar messages [ 2193.886706] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2193.896975] Lustre: Skipped 4 previous similar messages [ 2193.971113] Lustre: 42788:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2194.166046] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1584 to 0x280000400:1601) [ 2194.167500] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1584 to 0x240000400:1601) [ 2197.720929] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2199.022545] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2199.032653] Lustre: Skipped 6 previous similar messages [ 2205.197317] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2206.238214] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2212.661166] Lustre: DEBUG MARKER: == replay-dual test 20: recovery time is not increasing == 15:07:42 (1786734462) [ 2215.787155] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2217.647549] Lustre: Failing over lustre-MDT0000 [ 2217.958644] Lustre: server umount lustre-MDT0000 complete [ 2239.383579] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2374.500927] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2374.503514] Lustre: 44323:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 1dc5bb8e-1fa1-457c-b2c7-f5f2ab9df6de@ [ 2374.511335] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2374.577780] Lustre: 44323:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2374.587171] Lustre: 44323:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 2 previous similar messages [ 2374.691452] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1603 to 0x280000400:1633) [ 2374.698838] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1584 to 0x240000400:1633) [ 2380.629096] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2382.287464] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2388.992172] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2391.547085] Lustre: Failing over lustre-MDT0000 [ 2392.032048] Lustre: server umount lustre-MDT0000 complete [ 2413.769160] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2478.559359] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786734644/real 1786734644] req@ffff90a351078a80 x1873524629755136/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786734729 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2478.614705] Lustre: 3309:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 2550.501590] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2550.509436] Lustre: 45713:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 342955b0-8559-4969-a8bf-61b8bdf1da46@ [ 2550.528885] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2550.603300] Lustre: 45713:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2550.620494] Lustre: 45713:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 2 previous similar messages [ 2550.857385] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1635 to 0x240000400:1665) [ 2550.863745] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1603 to 0x280000400:1665) [ 2558.365157] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2560.536424] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2570.556293] Lustre: DEBUG MARKER: == replay-dual test 21a: commit on sharing =============== 15:13:40 (1786734820) [ 2575.223391] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2577.266217] Lustre: Failing over lustre-MDT0000 [ 2577.591937] Lustre: server umount lustre-MDT0000 complete [ 2595.190872] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2595.194715] Lustre: Skipped 4 previous similar messages [ 2599.998239] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2736.500150] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2736.506179] Lustre: 47359:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 65ea9805-ddd5-4f22-a133-1c6119572e12@ [ 2736.513893] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2736.571594] Lustre: lustre-MDT0000: Recovery over after 2:20, of 2 clients 1 recovered and 1 was evicted. [ 2736.578124] Lustre: Skipped 3 previous similar messages [ 2736.622890] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1667 to 0x280000400:1697) [ 2736.623937] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1635 to 0x240000400:1697) [ 2746.435788] Lustre: DEBUG MARKER: SKIP: replay-dual test_21b skipping SLOW test 21b [ 2747.873494] Lustre: DEBUG MARKER: == replay-dual test 22a: c1 lfs mkdir -i 1 dir1, M1 drop reply [ 2749.639524] Lustre: DEBUG MARKER: SKIP: replay-dual test_22a needs >= 2 MDTs [ 2751.709211] Lustre: DEBUG MARKER: == replay-dual test 22b: c1 lfs mkdir -i 1 d1, M1 drop reply [ 2753.174466] Lustre: DEBUG MARKER: SKIP: replay-dual test_22b needs >= 2 MDTs [ 2754.862608] Lustre: DEBUG MARKER: == replay-dual test 22c: c1 lfs mkdir -i 1 d1, M1 drop update [ 2756.263212] Lustre: DEBUG MARKER: SKIP: replay-dual test_22c needs >= 2 MDTs [ 2757.920064] Lustre: DEBUG MARKER: == replay-dual test 22d: c1 lfs mkdir -i 1 d1, M1 drop update [ 2759.526950] Lustre: DEBUG MARKER: SKIP: replay-dual test_22d needs >= 2 MDTs [ 2761.157567] Lustre: DEBUG MARKER: == replay-dual test 23a: c1 rmdir d1, M1 drop reply and fail, client2 mkdir d1 ========================================================== 15:16:50 (1786735010) [ 2762.624431] Lustre: DEBUG MARKER: SKIP: replay-dual test_23a needs >= 2 MDTs [ 2764.327843] Lustre: DEBUG MARKER: == replay-dual test 23b: c1 rmdir d1, M1 drop reply and fail M0/M1, c2 mkdir d1 ========================================================== 15:16:53 (1786735013) [ 2766.088485] Lustre: DEBUG MARKER: SKIP: replay-dual test_23b needs >= 2 MDTs [ 2768.339923] Lustre: DEBUG MARKER: == replay-dual test 23c: c1 rmdir d1, M0 drop update reply and fail M0, c2 mkdir d1 ========================================================== 15:16:57 (1786735017) [ 2769.967639] Lustre: DEBUG MARKER: SKIP: replay-dual test_23c needs >= 2 MDTs [ 2771.836746] Lustre: DEBUG MARKER: == replay-dual test 23d: c1 rmdir d1, M0 drop update reply and fail M0/M1, c2 mkdir d1 ========================================================== 15:17:01 (1786735021) [ 2773.563664] Lustre: DEBUG MARKER: SKIP: replay-dual test_23d needs >= 2 MDTs [ 2775.533684] Lustre: DEBUG MARKER: == replay-dual test 24: reconstruct on non-existing object ========================================================== 15:17:04 (1786735024) [ 2776.934873] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 2776.942046] LustreError: 47724:0:(ldlm_lib.c:3345:target_send_reply_msg()) @@@ dropping reply req@ffff90a24c10a680 x1873524610029440/t94489280518(0) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:427/0 lens 488/456 e 0 to 0 dl 1786735107 ref 1 fl Interpret:/200/0 rc 0/0 job:'truncate.0' uid:0 gid:0 projid:4294967295 [ 2861.517544] Lustre: lustre-MDT0000: Client caa734c7-06f2-48ac-a1c1-594bc1bac149 (at 192.168.206.53@tcp) reconnecting [ 2861.563400] Lustre: 47322:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff90a3794a5880 x1873524610029440/t94489280518(0) o36->caa734c7-06f2-48ac-a1c1-594bc1bac149@192.168.206.53@tcp:512/0 lens 488/3152 e 0 to 0 dl 1786735192 ref 1 fl Interpret:/202/0 rc 0/0 job:'truncate.0' uid:0 gid:0 projid:4294967295 [ 2868.732829] Lustre: DEBUG MARKER: == replay-dual test 25: replay|resend ==================== 15:18:37 (1786735117) [ 2870.618137] Lustre: *** cfs_fail_loc=304, val=0*** [ 2872.941371] Lustre: Failing over lustre-OST0000 [ 2873.055146] Lustre: server umount lustre-OST0000 complete [ 2875.375308] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2875.382591] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2875.406141] Lustre: Skipped 6 previous similar messages [ 2875.416763] LustreError: 12721:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2875.447807] LustreError: 12721:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 2876.881476] LustreError: 6598:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2876.911944] LustreError: 6598:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 2881.967803] LustreError: 12721:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2881.992485] LustreError: 12721:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 2887.113346] LustreError: 38639:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2887.139741] LustreError: 38639:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 2892.224216] LustreError: 12722:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2892.258989] LustreError: 12722:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 2893.125047] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2893.138041] Lustre: Skipped 3 previous similar messages [ 2894.166226] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 2894.172305] Lustre: Skipped 3 previous similar messages [ 2895.085300] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2895.100779] Lustre: Skipped 7 previous similar messages [ 2900.255496] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2914.875761] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 2918.197989] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 2937.327931] Lustre: DEBUG MARKER: == replay-dual test 26: dbench and tar with mds failover ========================================================== 15:19:45 (1786735185) [ 2945.137655] LustreError: 50980:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2945.148641] LustreError: 50980:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 2946.986662] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2951.238702] Lustre: DEBUG MARKER: test_26 fail mds1 1 times [ 2953.920111] Lustre: Failing over lustre-MDT0000 [ 2954.031985] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.53@tcp (stopping) [ 2954.469408] Lustre: server umount lustre-MDT0000 complete [ 2970.081255] LustreError: MGC192.168.206.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2970.093358] LustreError: Skipped 3 previous similar messages [ 2980.328069] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9b728c5daca28f00 [ 2986.847333] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 2993.669712] Lustre: 51648:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2993.689696] Lustre: 51648:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 2 previous similar messages [ 2996.997514] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1740 to 0x280000400:1761) [ 2997.000822] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1741 to 0x240000400:1761) [ 3005.257044] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3007.638930] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3017.197835] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3021.435699] Lustre: DEBUG MARKER: test_26 fail mds1 2 times [ 3024.029881] Lustre: Failing over lustre-MDT0000 [ 3024.139680] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.53@tcp (stopping) [ 3024.580360] Lustre: server umount lustre-MDT0000 complete [ 3053.030449] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9b728c5daca2f640 [ 3059.689974] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 3064.378741] Lustre: 53061:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 3064.388341] Lustre: 53061:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 252 previous similar messages [ 3067.776220] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1846 to 0x280000400:1889) [ 3067.786672] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1846 to 0x240000400:1889) [ 3074.796696] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3077.022606] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3086.497381] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3090.617726] Lustre: DEBUG MARKER: test_26 fail mds1 3 times [ 3093.002942] Lustre: Failing over lustre-MDT0000 [ 3093.487278] Lustre: server umount lustre-MDT0000 complete [ 3111.391129] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786735346/real 1786735346] req@ffff90a348e74000 x1873524630009856/t0(0) o400->MGC192.168.206.153@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786735362 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3111.437688] Lustre: 3311:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 26 previous similar messages [ 3117.159689] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 3129.999725] Lustre: 54487:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 3130.014021] Lustre: 54487:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 296 previous similar messages [ 3132.508546] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1957 to 0x240000400:1985) [ 3132.510669] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1958 to 0x280000400:1985) [ 3139.327336] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3141.364449] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3187.461776] Lustre: DEBUG MARKER: == replay-dual test 28: lock replay should be ordered: waiting after granted ========================================================== 15:23:56 (1786735436) [ 3215.707099] Lustre: Failing over lustre-OST0000 [ 3215.903961] Lustre: server umount lustre-OST0000 complete [ 3216.847768] LustreError: 53586:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3216.872457] LustreError: 53586:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 3234.649515] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3234.658315] Lustre: Skipped 4 previous similar messages [ 3236.521199] Lustre: *** cfs_fail_loc=32a, val=0*** [ 3241.879306] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 3252.977360] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 3255.442477] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3268.204272] Lustre: DEBUG MARKER: == replay-dual test 29: replay vs update with the same xid ========================================================== 15:25:16 (1786735516) [ 3270.035134] Lustre: DEBUG MARKER: SKIP: replay-dual test_29 needs >= 2 MDTs [ 3272.124330] Lustre: DEBUG MARKER: == replay-dual test 30: layout lock replay is not blocked on IO ========================================================== 15:25:21 (1786735521) [ 3275.944638] Lustre: Failing over lustre-MDT0000 [ 3276.401518] Lustre: server umount lustre-MDT0000 complete [ 3294.670429] LustreError: 57897:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.53@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3294.715054] LustreError: 57897:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 9 previous similar messages [ 3299.891544] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 3306.530146] Lustre: 57932:0:(ldlm_lib.c:2084:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 3306.544098] Lustre: 57932:0:(ldlm_lib.c:2084:extend_recovery_timer()) Skipped 275 previous similar messages [ 3306.718447] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2027 to 0x240000400:2049) [ 3306.723305] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2027 to 0x280000400:2049) [ 3313.254598] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3315.074363] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3325.345839] Lustre: DEBUG MARKER: == replay-dual test 31: deadlock on file_remove_privs and occupied mod rpc slots ========================================================== 15:26:14 (1786735574) [ 3329.623033] Lustre: Failing over lustre-OST0000 [ 3329.786969] Lustre: server umount lustre-OST0000 complete [ 3331.054561] LustreError: 51634:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3350.108120] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3350.124373] Lustre: Skipped 6 previous similar messages [ 3355.012736] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing set_default_debug -1 all [ 3364.266358] Lustre: DEBUG MARKER: oleg653-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 3366.033527] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in IDLE [ 3375.885353] Lustre: DEBUG MARKER: == replay-dual test 32: gap in update llog shouldn't break recovery ========================================================== 15:27:05 (1786735625) [ 3377.704293] Lustre: DEBUG MARKER: SKIP: replay-dual test_32 needs >= 2 MDTs [ 3379.598455] Lustre: DEBUG MARKER: == replay-dual test 33: Check for OBD_INCOMPAT_MULTI_RPCS in last_rcvd after abort_recovery ========================================================== 15:27:08 (1786735628) [ 3381.491494] Lustre: DEBUG MARKER: SKIP: replay-dual test_33 ldiskfs only test [ 3383.138588] Lustre: DEBUG MARKER: == replay-dual test complete, duration 3158 sec ========== 15:27:12 (1786735632) [ 3384.745365] Lustre: DEBUG MARKER: === replay-dual: start cleanup 15:27:14 (1786735634) === [ 3392.492519] Lustre: DEBUG MARKER: === replay-dual: finish cleanup 15:27:21 (1786735641) === [ 3399.660445] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3399.667037] Lustre: Skipped 1 previous similar message [ 3403.334306] Lustre: server umount lustre-MDT0000 complete [ 3407.390676] LustreError: 11222:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786735658 with bad export cookie 11201169557180147101 [ 3407.419724] LustreError: 11222:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3407.488989] Lustre: server umount lustre-OST0000 complete [ 3411.424826] Lustre: server umount lustre-OST0001 complete [ 3424.228779] Lustre: DEBUG MARKER: oleg653-server.virtnet: executing unload_modules_local [ 3426.953300] Key type lgssc unregistered [ 3427.311161] LNet: 61858:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3427.325523] LNetError: 61858:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3427.346214] LNet: Removed LNI 192.168.206.153@tcp [ 3428.392360] Key type .llcrypt unregistered [ 3428.395610] Key type ._llcrypt unregistered