[ 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 465607449 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: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K 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.001012] APIC: Switch to symmetric I/O mode setup [ 0.003128] x2apic enabled [ 0.004006] Switched APIC routing to physical x2apic. [ 0.005013] kvm-guest: setup PV IPIs [ 0.008620] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009022] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010013] pid_max: default: 32768 minimum: 301 [ 0.011127] LSM: Security Framework initializing [ 0.012053] Yama: becoming mindful. [ 0.013044] SELinux: Initializing. [ 0.014068] *** VALIDATE selinux *** [ 0.022686] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027974] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029158] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031145] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032115] *** VALIDATE tmpfs *** [ 0.034435] *** VALIDATE proc *** [ 0.035251] *** VALIDATE cgroup *** [ 0.036011] *** VALIDATE cgroup2 *** [ 0.037264] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038152] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040039] Spectre V2 : User space: Vulnerable [ 0.041016] Speculative Store Bypass: Vulnerable [ 0.044276] debug: unmapping init [mem 0xffffffffad059000-0xffffffffad060fff] [ 0.046169] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047596] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048027] ... version: 2 [ 0.049011] ... bit width: 48 [ 0.050010] ... generic registers: 4 [ 0.051012] ... value mask: 0000ffffffffffff [ 0.052017] ... max period: 00007fffffffffff [ 0.053016] ... fixed-purpose events: 3 [ 0.054013] ... event mask: 000000070000000f [ 0.055300] rcu: Hierarchical SRCU implementation. [ 0.057455] smp: Bringing up secondary CPUs ... [ 0.058594] x86: Booting SMP configuration: [ 0.059025] .... node #0, CPUs: #1 #2 #3 [ 0.062403] smp: Brought up 1 node, 4 CPUs [ 0.064012] smpboot: Max logical packages: 1 [ 0.065018] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.104516] node 0 deferred pages initialised in 37ms [ 0.110221] devtmpfs: initialized [ 0.112281] x86/mm: Memory block size: 128MB [ 0.115959] gcov: version magic: 0x41383552 [ 0.119151] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.120082] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.123340] pinctrl core: initialized pinctrl subsystem [ 0.125184] [ 0.125761] ************************************************************* [ 0.128016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.131010] ** ** [ 0.132025] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.135012] ** ** [ 0.137011] ** This means that this kernel is built to expose internal ** [ 0.140011] ** IOMMU data structures, which may compromise security on ** [ 0.142010] ** your system. ** [ 0.144012] ** ** [ 0.146013] ** If you see this message and you are not debugging the ** [ 0.149017] ** kernel, report this immediately to your vendor! ** [ 0.151011] ** ** [ 0.153010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.155012] ************************************************************* [ 0.158611] NET: Registered protocol family 16 [ 0.160405] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.162057] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.165060] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.169016] cpuidle: using governor menu [ 0.170832] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.173586] PCI: Using configuration type 1 for base access [ 0.176190] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.186104] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.189043] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.193129] cryptd: max_cpu_qlen set to 1000 [ 0.196274] ACPI: Added _OSI(Module Device) [ 0.198017] ACPI: Added _OSI(Processor Device) [ 0.200024] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.202019] ACPI: Added _OSI(Processor Aggregator Device) [ 0.207074] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.214284] ACPI: Interpreter enabled [ 0.216052] ACPI: PM: (supports S0 S3 S4 S5) [ 0.217011] ACPI: Using IOAPIC for interrupt routing [ 0.219096] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.223399] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.231855] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.234037] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.239021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.243078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.248542] acpiphp: Slot [2] registered [ 0.250097] acpiphp: Slot [5] registered [ 0.251099] acpiphp: Slot [6] registered [ 0.253135] acpiphp: Slot [7] registered [ 0.254125] acpiphp: Slot [8] registered [ 0.256210] acpiphp: Slot [9] registered [ 0.257181] acpiphp: Slot [10] registered [ 0.259125] acpiphp: Slot [3] registered [ 0.260114] acpiphp: Slot [4] registered [ 0.261000] acpiphp: Slot [11] registered [ 0.261000] acpiphp: Slot [12] registered [ 0.263121] acpiphp: Slot [13] registered [ 0.264074] acpiphp: Slot [14] registered [ 0.265062] acpiphp: Slot [15] registered [ 0.266079] acpiphp: Slot [16] registered [ 0.267082] acpiphp: Slot [17] registered [ 0.268061] acpiphp: Slot [18] registered [ 0.269085] acpiphp: Slot [19] registered [ 0.271082] acpiphp: Slot [20] registered [ 0.272094] acpiphp: Slot [21] registered [ 0.273097] acpiphp: Slot [22] registered [ 0.275081] acpiphp: Slot [23] registered [ 0.276064] acpiphp: Slot [24] registered [ 0.277095] acpiphp: Slot [25] registered [ 0.279092] acpiphp: Slot [26] registered [ 0.280222] acpiphp: Slot [27] registered [ 0.282074] acpiphp: Slot [28] registered [ 0.283162] acpiphp: Slot [29] registered [ 0.285121] acpiphp: Slot [30] registered [ 0.287097] acpiphp: Slot [31] registered [ 0.288136] PCI host bridge to bus 0000:00 [ 0.290020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.293021] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.295022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.299023] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.302067] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.305020] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.307115] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.311122] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.314314] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.325014] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.330436] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.333017] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.336016] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.338022] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.340693] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.344088] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.348051] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.352851] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.360014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.373014] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.378013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.384265] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.395018] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.404017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.425018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.439311] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.445011] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.453012] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.474016] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.486717] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.498017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.505137] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.524958] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.537536] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.547012] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.552011] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.571013] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.583527] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.595022] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.602016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.624015] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.638362] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.645016] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.655017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.682025] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.693483] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.696450] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.699382] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.704382] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.707251] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.713048] iommu: Default domain type: Passthrough [ 0.714402] SCSI subsystem initialized [ 0.715153] ACPI: bus type USB registered [ 0.717110] usbcore: registered new interface driver usbfs [ 0.719083] usbcore: registered new interface driver hub [ 0.721171] usbcore: registered new device driver usb [ 0.723195] pps_core: LinuxPPS API ver. 1 registered [ 0.725016] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.727059] PTP clock support registered [ 0.730459] EDAC MC: Ver: 3.0.0 [ 0.731811] PCI: Using ACPI for IRQ routing [ 0.732897] NetLabel: Initializing [ 0.734017] NetLabel: domain hash size = 128 [ 0.736011] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.737080] NetLabel: unlabeled traffic allowed by default [ 0.740068] vgaarb: loaded [ 0.741258] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.743016] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.747315] clocksource: Switched to clocksource kvm-clock [ 0.851769] VFS: Disk quotas dquot_6.6.0 [ 0.852945] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.856164] *** VALIDATE ramfs *** [ 0.857213] *** VALIDATE hugetlbfs *** [ 0.858814] pnp: PnP ACPI init [ 0.861372] pnp: PnP ACPI: found 6 devices [ 0.880491] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.884618] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.887213] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.890015] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.892593] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.895091] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.897646] NET: Registered protocol family 2 [ 0.899667] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.904230] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.908086] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.913371] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.917061] TCP: Hash tables configured (established 65536 bind 65536) [ 0.919689] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.923180] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.926238] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.929609] NET: Registered protocol family 1 [ 0.932471] RPC: Registered named UNIX socket transport module. [ 0.934898] RPC: Registered udp transport module. [ 0.936236] RPC: Registered tcp transport module. [ 0.937351] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.939925] NET: Registered protocol family 44 [ 0.941320] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.944666] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.946953] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.948499] PCI: CLS 0 bytes, default 64 [ 0.950165] Unpacking initramfs... [ 2.331309] debug: unmapping init [mem 0xffff8a3afcc54000-0xffff8a3afffbffff] [ 2.335186] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.336926] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.339129] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.829418] Initialise system trusted keyrings [ 2.831192] Key type blacklist registered [ 2.833273] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.842967] zbud: loaded [ 2.846989] *** VALIDATE nfs *** [ 2.848412] *** VALIDATE nfs4 *** [ 2.850455] pstore: using deflate compression [ 2.856149] Platform Keyring initialized [ 2.958916] NET: Registered protocol family 38 [ 2.960323] Key type asymmetric registered [ 2.961458] Asymmetric key parser 'x509' registered [ 2.962966] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.965257] io scheduler mq-deadline registered [ 2.967299] io scheduler kyber registered [ 2.969222] io scheduler bfq registered [ 2.971746] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.975232] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.978511] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.982045] ACPI: Power Button [PWRF] [ 2.987665] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.994309] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.005862] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.012205] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.026585] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.053189] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.080652] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.086898] Non-volatile memory driver v1.3 [ 3.088978] Linux agpgart interface v0.103 [ 3.126066] virtio_blk virtio1: [vda] 145896 512-byte logical blocks (74.7 MB/71.2 MiB) [ 3.129488] vda: detected capacity change from 0 to 74698752 [ 3.147189] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.150318] vdb: detected capacity change from 0 to 1073741824 [ 3.168969] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.172584] vdc: detected capacity change from 0 to 2621440000 [ 3.194220] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.198062] vdd: detected capacity change from 0 to 2621440000 [ 3.215326] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.218615] vde: detected capacity change from 0 to 4294967296 [ 3.239385] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.242786] vdf: detected capacity change from 0 to 4294967296 [ 3.249474] libphy: Fixed MDIO Bus: probed [ 3.254299] usbcore: registered new interface driver usbserial_generic [ 3.256980] usbserial: USB Serial support registered for generic [ 3.259384] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.263839] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.265173] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.267282] mousedev: PS/2 mouse device common for all mice [ 3.270323] rtc_cmos 00:05: RTC can wake from S4 [ 3.273717] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.273749] rtc_cmos 00:05: registered as rtc0 [ 3.280029] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.280627] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.283897] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.287712] intel_pstate: CPU model not supported [ 3.289387] hid: raw HID events driver (C) Jiri Kosina [ 3.303346] usbcore: registered new interface driver usbhid [ 3.305878] usbhid: USB HID core driver [ 3.307630] drop_monitor: Initializing network drop monitor service [ 3.310243] Initializing XFRM netlink socket [ 3.312343] NET: Registered protocol family 10 [ 3.315295] Segment Routing with IPv6 [ 3.316722] NET: Registered protocol family 17 [ 3.319280] mpls_gso: MPLS GSO support [ 3.325269] RAS: Correctable Errors collector initialized. [ 3.328205] AVX version of gcm_enc/dec engaged. [ 3.330156] AES CTR mode by8 optimization enabled [ 3.398645] sched_clock: Marking stable (3398625497, 0)->(4374059926, -975434429) [ 3.404867] registered taskstats version 1 [ 3.407093] Loading compiled-in X.509 certificates [ 3.409456] zswap: loaded using pool lzo/zbud [ 3.436384] Key type big_key registered [ 3.449553] Key type encrypted registered [ 3.451169] ima: No TPM chip found, activating TPM-bypass! [ 3.453102] ima: Allocated hash algorithm: sha1 [ 3.454881] ima: No architecture policies found [ 3.456790] evm: Initialising EVM extended attributes: [ 3.458944] evm: security.selinux [ 3.459975] evm: security.ima [ 3.461244] evm: security.capability [ 3.462582] evm: HMAC attrs: 0x1 [ 3.464994] rtc_cmos 00:05: setting system clock to 2026-08-14 06:10:39 UTC (1786687839) [ 3.472369] debug: unmapping init [mem 0xffffffffae003000-0xffffffffae1fffff] [ 3.475915] debug: unmapping init [mem 0xffffffffacd82000-0xffffffffad058fff] [ 3.483082] Write protecting the kernel read-only data: 28672k [ 3.486806] debug: unmapping init [mem 0xffffffffab403000-0xffffffffab5fffff] [ 3.489908] debug: unmapping init [mem 0xffffffffabd14000-0xffffffffabdfffff] [ 3.522795] 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.531947] systemd[1]: Detected virtualization kvm. [ 3.533833] systemd[1]: Detected architecture x86-64. [ 3.535910] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.566246] systemd[1]: No hostname configured. [ 3.569294] systemd[1]: Set hostname to . [ 3.571223] random: systemd: uninitialized urandom read (16 bytes read) [ 3.574280] systemd[1]: Initializing machine ID from random generator. [ 3.643687] random: ln: uninitialized urandom read (6 bytes read) [ 3.735435] random: systemd: uninitialized urandom read (16 bytes read) [ 3.738149] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ 3.742299] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.747411] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Apply Kernel Variables... Starting Create Volatile Files and Directories... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Reached target Paths. Starting Setup Virtual Console... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.376477] device-mapper: uevent: version 1.0.3 [ 4.378773] 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 ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.081402] virtio_net virtio0 ens2: renamed from eth0 [ 5.089270] random: fast init done [ 5.145620] scsi host0: ata_piix [ 5.188354] scsi host1: ata_piix [ 5.189912] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.192679] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.696169] dracut-initqueue[579]: RTNETLINK answers: File exists [ 9.979969] random: crng init done [ 9.981957] 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.317790] 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... [ OK ] Stopped target Timers. 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 Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ 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.457843] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.726638] SELinux: Disabled at runtime. [ 11.791556] 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.799468] systemd[1]: Detected virtualization kvm. [ 11.801366] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.298919] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.302886] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.308730] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.312411] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.316850] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.327867] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.337989] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-serial\x2dgetty.slice. Activating swap /dev/disk/by-label/SWAP... Starting Remount Root and Kernel File Systems... Mounting Huge Pages File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ 12.387818] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-getty.slice. [ OK ] Listening on udev Control Socket. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on udev Kernel Socket. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Mounting Kernel Debug File System... Mounting POSIX Message Queue File System... Starting udev Coldplug all Devices... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target Paths. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting Apply Kernel Variables... [ OK ] Stopped target Initrd File Systems. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Apply Kernel Variables. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 12.760324] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.335260] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.405477] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.200716] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.347169] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (6s / no limit) [** ] A start job is running for Configur…-only root support (6s / no limit) [*** ] A start job is running for Configur…-only root support (7s / no limit)[ 19.274787] Key type dns_resolver registered [ *** ] A start job is running for Configur…-only root support (7s / no limit)[ 20.179423] NFS: Registering the id_resolver key type [ 20.182293] Key type id_resolver registered [ 20.184533] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (8s / no limit) [ ***] A start job is running for Configur…-only root support (8s / no limit) [ 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 Load/Save Random Seed... Starting Create Volatile Files and Directories... [ 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 dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ 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. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started Login Service. [ OK ] Started OpenSSH server daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ 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 Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg336-server login: [ 73.288660] libcfs: loading out-of-tree module taints kernel. [ 73.335381] Key type ._llcrypt registered [ 73.337874] Key type .llcrypt registered [ 73.450591] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_hostid [ 91.421438] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing load_modules_local [ 92.706359] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 92.719940] alg: No test for adler32 (adler32-zlib) [ 94.194507] Lustre: Lustre: Build Version: 2.17.57_1_g9a8e296 [ 95.377376] LNet: Added LNI 192.168.203.136@tcp [8/256/0/180] [ 97.231192] Key type lgssc registered [ 99.075873] Lustre: Echo OBD driver; http://www.lustre.org/ [ 112.503087] hrtimer: interrupt took 2002889 ns [ 118.378420] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 160.640617] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing load_modules_local [ 173.871410] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 173.917992] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 175.195570] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 175.226785] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 175.348433] Lustre: lustre-MDT0000: new disk, initializing [ 175.439293] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 175.471538] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 180.094143] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 193.030179] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 193.120771] Lustre: 6507:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 193.150266] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 193.154203] Lustre: Skipped 1 previous similar message [ 193.253357] Lustre: lustre-MDT0001: new disk, initializing [ 193.362606] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 193.395269] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 193.411804] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 197.657501] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 202.130246] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 211.470991] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 211.728536] Lustre: lustre-OST0000: new disk, initializing [ 211.734631] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 211.741496] Lustre: 8444:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 211.817110] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 217.238577] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 217.626978] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 217.632314] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 217.735987] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 230.540552] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 230.672327] Lustre: lustre-OST0001: new disk, initializing [ 230.675587] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 230.681781] Lustre: 9515:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 230.744847] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 236.989304] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 237.138905] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 237.181504] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 237.269134] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 249.358443] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 255.993625] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 263.362899] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing check_logdir /tmp/testlogs/ [ 268.982234] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing yml_node [ 274.322615] Lustre: DEBUG MARKER: Client: 2.17.57.1 [ 277.399469] Lustre: DEBUG MARKER: MDS: 2.17.57.1 [ 279.675970] Lustre: DEBUG MARKER: OSS: 2.17.57.1 [ 281.009465] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Fri Aug 14 02:15:16 EDT 2026 [ 298.437439] Lustre: DEBUG MARKER: excepting tests: 110f 131b 59 36 [ 300.534315] Lustre: DEBUG MARKER: === replay-single: start setup 02:15:35 (1786688135) === [ 306.116484] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing check_config_client /mnt/lustre [ 324.882519] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 328.619715] Lustre: 13323:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 332.736205] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 338.350538] Lustre: DEBUG MARKER: === replay-single: finish setup 02:16:13 (1786688173) === [ 341.257159] Lustre: DEBUG MARKER: == replay-single test 100a: DNE: create striped dir, drop update rep from MDT1, fail MDT1 ========================================================== 02:16:16 (1786688176) [ 342.366668] Lustre: *** cfs_fail_loc=1701, val=2147483648*** [ 342.368865] LustreError: 7924:0:(ldlm_lib.c:3346:target_send_reply_msg()) @@@ dropping reply req@ffff8a3b412ab800 x1873478084047872/t4294967300(0) o1000->lustre-MDT0000-mdtlov_UUID@0@lo:319/0 lens 264/4320 e 0 to 0 dl 1786688189 ref 1 fl Interpret:/200/0 rc 0/0 job:'osp_up1-0.0' uid:0 gid:0 projid:4294967295 [ 343.731890] Lustre: Failing over lustre-MDT0001 [ 343.864055] Lustre: server umount lustre-MDT0001 complete [ 345.060473] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 345.083705] Lustre: Skipped 1 previous similar message [ 350.176256] LustreError: 13935:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 350.197481] LustreError: 13935:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 7 previous similar messages [ 352.261486] LustreError: 6515:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.36@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 355.303655] LustreError: 13685:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 355.326646] LustreError: 13685:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 357.379847] LustreError: 6514:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.36@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 358.879177] Lustre: 7919:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688178/real 1786688178] req@ffff8a3b412aa680 x1873478084047872/t0(0) o1000->lustre-MDT0001-osp-MDT0000@0@lo:24/4 lens 264/4320 e 0 to 1 dl 1786688194 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'osp_up1-0.0' uid:0 gid:0 projid:4294967295 [ 362.500681] LustreError: 6513:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.36@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 362.542892] LustreError: 6513:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 363.901523] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 364.237903] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 366.303725] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 369.341163] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 369.655845] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 369.713800] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 380.725609] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 382.846495] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 393.592583] Lustre: DEBUG MARKER: == replay-single test 100b: DNE: create striped dir, fail MDT0 ========================================================== 02:17:08 (1786688228) [ 394.936466] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 394.956727] LustreError: 8452:0:(ldlm_lib.c:3346:target_send_reply_msg()) @@@ dropping reply req@ffff8a3b7dfc9500 x1873478065113344/t4294967363(0) o36->90ecce1b-ed05-49f4-8ec1-539f19cf349a@192.168.203.36@tcp:410/0 lens 560/536 e 0 to 0 dl 1786688280 ref 1 fl Interpret:/200/0 rc 0/0 job:'lfs.0' uid:0 gid:0 projid:4294967295 [ 396.986556] Lustre: Failing over lustre-MDT0000 [ 397.367221] LustreError: 6514:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.36@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 397.427368] Lustre: server umount lustre-MDT0000 complete [ 399.840488] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 399.844911] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 399.868749] Lustre: Skipped 1 previous similar message [ 415.728217] LustreError: 6519:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 415.754294] LustreError: 6519:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 19 previous similar messages [ 416.735164] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688236/real 1786688236] req@ffff8a3b7f5a5500 x1873478084090752/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786688252 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 416.775337] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 418.557576] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 426.979416] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28c04b6 [ 426.990550] Lustre: MGC192.168.203.136@tcp: Connection restored to 0@lo (at 0@lo) [ 426.996411] Lustre: Skipped 2 previous similar messages [ 427.190160] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 428.047506] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 432.624219] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 432.691587] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 432.712050] Lustre: 6514:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8a3b7e521880 x1873478065113344/t4294967363(0) o36->90ecce1b-ed05-49f4-8ec1-539f19cf349a@192.168.203.36@tcp:448/0 lens 560/2880 e 0 to 0 dl 1786688318 ref 1 fl Interpret:/202/0 rc 0/0 job:'lfs.0' uid:0 gid:0 projid:4294967295 [ 432.751946] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:6 to 0x280000401:33) [ 432.753509] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:6 to 0x2c0000401:33) [ 433.484954] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 443.258451] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 444.697696] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 453.888939] Lustre: DEBUG MARKER: == replay-single test 100c: DNE: create striped dir, abort_recov_mdt mds2 ========================================================== 02:18:08 (1786688288) [ 462.199815] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 464.898060] Lustre: Failing over lustre-MDT0001 [ 465.289149] Lustre: server umount lustre-MDT0001 complete [ 468.449157] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 468.457129] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 468.458102] LustreError: 6514:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 468.458111] LustreError: 6514:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 14 previous similar messages [ 468.574689] Lustre: Skipped 5 previous similar messages [ 482.043455] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 482.046989] LDISKFS-fs (dm-1): recovery complete [ 482.063636] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 482.499288] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 482.540182] Lustre: lustre-MDT0001: Aborting MDT recovery [ 484.354971] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 487.509574] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 487.918395] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 487.934331] Lustre: Skipped 3 previous similar messages [ 488.045073] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 488.057573] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 488.085611] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 488.151534] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:46 to 0x280000400:65) [ 488.155811] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:46 to 0x2c0000400:65) [ 504.009480] Lustre: Failing over lustre-MDT0001 [ 504.282885] Lustre: server umount lustre-MDT0001 complete [ 508.390863] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 508.409938] Lustre: Skipped 2 previous similar messages [ 522.297056] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 522.555838] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 524.011709] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 526.859586] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 527.863423] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 527.871470] Lustre: Skipped 2 previous similar messages [ 527.902813] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 527.958345] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:97) [ 527.960627] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 538.291688] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 540.435870] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 551.090515] Lustre: DEBUG MARKER: == replay-single test 100d: DNE: cancel update logs upon recovery abort ========================================================== 02:19:45 (1786688385) [ 567.573674] Lustre: Failing over lustre-MDT0001 [ 567.878779] Lustre: server umount lustre-MDT0001 complete [ 568.804834] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 568.813566] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 568.814106] LustreError: 6513:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 568.814114] LustreError: 6513:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 24 previous similar messages [ 568.875091] Lustre: Skipped 2 previous similar messages [ 576.823630] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 577.224655] Lustre: lustre-MDT0001: Aborting client recovery [ 577.233383] LustreError: 20179:0:(ldlm_lib.c:3004:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 577.233933] LustreError: 20201:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osd: get update log duration 0, retries 0, failed: rc = -108 [ 577.246808] Lustre: 20203:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 577.266710] Lustre: 20203:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 90ecce1b-ed05-49f4-8ec1-539f19cf349a@ [ 577.276026] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 577.286340] Lustre: lustre-MDT0001-osd: cancel update llog [0x2400013a0:0x3:0x0] [ 577.296926] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000bd1:0x3:0x0] [ 577.342035] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:129) [ 577.350279] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 581.720821] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 582.648175] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 582.680257] Lustre: Skipped 2 previous similar messages [ 582.683348] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 603.426992] Lustre: DEBUG MARKER: == replay-single test 100e: DNE: create striped dir on MDT0 and MDT1, fail MDT0, MDT1 ========================================================== 02:20:38 (1786688438) [ 611.438718] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 620.238028] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 622.294188] Lustre: Failing over lustre-MDT0000 [ 622.584871] Lustre: server umount lustre-MDT0000 complete [ 623.075453] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 623.088096] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 626.484353] Lustre: Failing over lustre-MDT0001 [ 626.486332] LustreError: 6497:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786688462 with bad export cookie 2724514938969916598 [ 626.495883] LustreError: 6497:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 626.499922] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 626.931025] Lustre: server umount lustre-MDT0001 complete [ 651.401515] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 651.405525] LDISKFS-fs (dm-0): recovery complete [ 651.416768] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 651.548694] LDISKFS-fs (dm-1): 5 truncates cleaned up [ 651.550376] LDISKFS-fs (dm-1): recovery complete [ 651.564362] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 671.653854] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28c6065 [ 671.679335] Lustre: MGC192.168.203.136@tcp: Connection restored to 0@lo (at 0@lo) [ 671.703778] Lustre: Skipped 2 previous similar messages [ 672.169190] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 672.198021] Lustre: Skipped 3 previous similar messages [ 672.266381] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 672.276405] Lustre: Skipped 1 previous similar message [ 672.352867] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 672.718461] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 673.057693] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 678.387985] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 679.542195] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 680.033257] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 683.489332] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688464/real 1786688464] req@ffff8a3a4989ce00 x1873478084442624/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786688519 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 683.549358] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 686.559200] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688467/real 1786688467] req@ffff8a3b459f4a80 x1873478084442880/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786688522 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 686.606753] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 691.743149] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688472/real 1786688472] req@ffff8a3b459f6300 x1873478084443520/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786688527 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 691.786491] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 693.303319] Lustre: lustre-MDT0001: Recovery over after 0:15, of 2 clients 2 recovered and 0 were evicted. [ 693.338319] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:161) [ 693.350736] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:161) [ 693.539425] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:65) [ 693.539884] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:65) [ 700.064283] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 701.510425] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 703.328905] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 703.992882] Lustre: 3641:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688484/real 1786688484] req@ffff8a3b459f5180 x1873478084444160/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786688539 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 704.041118] Lustre: 3641:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 711.642356] Lustre: DEBUG MARKER: == replay-single test 101: Shouldn't reassign precreated objs to other files after recovery ========================================================== 02:22:26 (1786688546) [ 720.004177] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 723.423181] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688504/real 1786688504] req@ffff8a3a4989c700 x1873478084445952/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786688559 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 723.458198] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 744.327020] Lustre: Failing over lustre-MDT0000 [ 744.492971] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.36@tcp (stopping) [ 744.733205] Lustre: server umount lustre-MDT0000 complete [ 744.928042] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 744.939888] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 744.944822] LustreError: 23153:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 744.958164] Lustre: Skipped 4 previous similar messages [ 744.981923] LustreError: 23153:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 19 previous similar messages [ 757.718438] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 757.723867] LDISKFS-fs (dm-0): recovery complete [ 757.731899] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 757.808286] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 758.007411] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 758.007702] Lustre: lustre-MDT0000: Aborting client recovery [ 758.015593] LustreError: 25598:0:(ldlm_lib.c:3004:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 758.024812] Lustre: 25631:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 758.033303] Lustre: 25631:0:(ldlm_lib.c:2404:target_recovery_overseer()) Skipped 2 previous similar messages [ 758.038697] Lustre: 25631:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 90ecce1b-ed05-49f4-8ec1-539f19cf349a@ [ 758.051792] Lustre: 25631:0:(genops.c:1622:class_disconnect_stale_exports()) Skipped 1 previous similar message [ 758.059752] Lustre: lustre-MDT0000: disconnecting 2 stale clients [ 758.068764] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 758.089573] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 758.151896] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:609) [ 758.153149] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:609) [ 762.850964] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 763.388960] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 763.398052] Lustre: Skipped 6 previous similar messages [ 858.717101] Lustre: DEBUG MARKER: == replay-single test 102a: check resend (request lost) with multiple modify RPCs in flight ========================================================== 02:24:52 (1786688692) [ 860.734357] Lustre: *** cfs_fail_loc=159, val=0*** [ 916.569424] Lustre: lustre-MDT0001: Client 90ecce1b-ed05-49f4-8ec1-539f19cf349a (at 192.168.203.36@tcp) reconnecting [ 924.774955] Lustre: DEBUG MARKER: == replay-single test 102b: check resend (reply lost) with multiple modify RPCs in flight ========================================================== 02:25:59 (1786688759) [ 926.332715] Lustre: *** cfs_fail_loc=15a, val=0*** [ 981.016672] Lustre: lustre-MDT0000: Client 90ecce1b-ed05-49f4-8ec1-539f19cf349a (at 192.168.203.36@tcp) reconnecting [ 981.050893] Lustre: 24240:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8a3b7eea2300 x1873478068112768/t17179873235(0) o36->90ecce1b-ed05-49f4-8ec1-539f19cf349a@192.168.203.36@tcp:242/0 lens 488/3152 e 0 to 0 dl 1786688867 ref 1 fl Interpret:/202/0 rc 0/0 job:'chmod.0' uid:0 gid:0 projid:4294967295 [ 981.083212] Lustre: 24240:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 6 previous similar messages [ 988.926641] Lustre: DEBUG MARKER: == replay-single test 102c: check replay w/o reconstruction with multiple mod RPCs in flight ========================================================== 02:27:03 (1786688823) [ 998.042979] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 999.374060] Lustre: *** cfs_fail_loc=15a, val=0*** [ 999.384726] Lustre: Skipped 7 previous similar messages [ 1003.306059] Lustre: Failing over lustre-MDT0001 [ 1003.765736] Lustre: server umount lustre-MDT0001 complete [ 1004.004219] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1004.012200] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 1004.029014] LustreError: 24240:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 1004.068246] LustreError: 24240:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 12 previous similar messages [ 1028.274802] LDISKFS-fs (dm-1): 7 truncates cleaned up [ 1028.276845] LDISKFS-fs (dm-1): recovery complete [ 1028.308870] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1028.688538] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1028.695994] Lustre: Skipped 2 previous similar messages [ 1028.720611] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1028.726050] Lustre: Skipped 2 previous similar messages [ 1030.489933] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1030.498858] Lustre: Skipped 1 previous similar message [ 1033.640923] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1033.706890] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1033.714927] Lustre: Skipped 2 previous similar messages [ 1033.750185] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 1033.759699] Lustre: Skipped 1 previous similar message [ 1033.807813] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 1033.808218] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 1043.954953] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 1045.590313] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1054.812697] Lustre: DEBUG MARKER: == replay-single test 102d: check replay [ 1056.634403] Lustre: *** cfs_fail_loc=15a, val=0*** [ 1056.636258] Lustre: Skipped 4 previous similar messages [ 1061.277524] Lustre: Failing over lustre-MDT0000 [ 1061.601979] Lustre: server umount lustre-MDT0000 complete [ 1064.417029] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1079.785604] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1079.924180] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1080.231557] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1081.358985] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1085.412133] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1085.440439] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 1085.492896] Lustre: 23153:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8a3a41ed1f80 x1873478068176128/t17179873294(0) o36->90ecce1b-ed05-49f4-8ec1-539f19cf349a@192.168.203.36@tcp:346/0 lens 488/3152 e 0 to 0 dl 1786688971 ref 1 fl Interpret:/202/0 rc 0/0 job:'chmod.0' uid:0 gid:0 projid:4294967295 [ 1085.525899] Lustre: 23153:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 6 previous similar messages [ 1085.534501] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1153) [ 1085.534581] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1153) [ 1095.180638] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1096.753783] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1105.758700] Lustre: DEBUG MARKER: == replay-single test 103: Check otr_next_id overflow ==== 02:29:00 (1786688940) [ 1109.671639] Lustre: Failing over lustre-MDT0000 [ 1109.935456] Lustre: server umount lustre-MDT0000 complete [ 1127.395832] Lustre: 3641:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786688947/real 1786688947] req@ffff8a3a49f80e00 x1873478085113600/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786688963 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1127.454347] Lustre: 3641:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 1127.465928] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1130.149868] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1137.631660] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b7eea0a80 x1873478085128832/t0(0) o250->MGC192.168.203.136@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 [ 1137.732505] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.36@tcp (not set up) [ 1137.817893] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1138.760671] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1141.662605] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1143.312029] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 1143.345239] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1185) [ 1143.345294] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1185) [ 1150.176929] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1151.675135] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1161.549930] Lustre: DEBUG MARKER: == replay-single test 110a: DNE: create striped dir, fail MDT1 ========================================================== 02:29:56 (1786688996) [ 1169.312603] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1171.714622] Lustre: Failing over lustre-MDT0000 [ 1171.966600] Lustre: server umount lustre-MDT0000 complete [ 1173.988203] 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 [ 1173.996378] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1174.002231] Lustre: Skipped 12 previous similar messages [ 1174.013114] LustreError: Skipped 1 previous similar message [ 1190.372764] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1193.502631] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1193.508170] LDISKFS-fs (dm-0): recovery complete [ 1193.519097] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1200.608359] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b6c6d6680 x1873478085167360/t0(0) o250->MGC192.168.203.136@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 [ 1200.884168] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1204.918409] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1206.249452] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1206.261924] Lustre: Skipped 10 previous similar messages [ 1206.383459] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1217) [ 1206.388043] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1217) [ 1214.463908] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1216.015987] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1225.248749] Lustre: DEBUG MARKER: == replay-single test 110b: DNE: create striped dir, fail MDT1 and client ========================================================== 02:31:00 (1786689060) [ 1232.705920] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1235.487972] Lustre: Failing over lustre-MDT0000 [ 1235.715806] Lustre: server umount lustre-MDT0000 complete [ 1252.320697] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786689072/real 1786689072] req@ffff8a3a46bde300 x1873478085199744/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786689088 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1252.357695] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1252.373810] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1259.941604] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1259.946298] LDISKFS-fs (dm-0): recovery complete [ 1259.958464] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1262.187875] LustreError: 34976:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 1262.204371] LustreError: 34976:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8a3a48ff9180 x1873478085205632/t0(0) o250->MGC192.168.203.136@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786689098 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1262.225226] LustreError: 34976:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 1262.563382] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3a41ed3100 x1873478085207296/t0(0) o250->MGC192.168.203.136@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 [ 1263.088245] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1268.194173] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1268.207787] Lustre: Skipped 1 previous similar message [ 1269.207590] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1279.071884] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1281.625789] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:56 [ 1286.664149] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:51 [ 1291.780546] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:46 [ 1296.899185] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:41 [ 1302.019728] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:36 [ 1312.265142] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:26 [ 1312.283282] Lustre: Skipped 1 previous similar message [ 1332.741973] Lustre: lustre-MDT0000: Denying connection for new client fe3c5e73-a34f-43e2-9899-221e6938ec03 (at 192.168.203.36@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:05 [ 1332.770495] Lustre: Skipped 3 previous similar messages [ 1338.500312] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1338.510057] Lustre: 35009:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 90ecce1b-ed05-49f4-8ec1-539f19cf349a@ [ 1338.526738] Lustre: 35009:0:(genops.c:1622:class_disconnect_stale_exports()) Skipped 1 previous similar message [ 1338.539327] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1338.599930] Lustre: lustre-MDT0000: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 1338.606448] Lustre: Skipped 1 previous similar message [ 1338.657918] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1249) [ 1338.657918] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1249) [ 1353.325199] Lustre: DEBUG MARKER: == replay-single test 110c: DNE: create striped dir, fail MDT2 ========================================================== 02:33:08 (1786689188) [ 1361.482913] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1363.531077] Lustre: Failing over lustre-MDT0001 [ 1364.059342] Lustre: server umount lustre-MDT0001 complete [ 1387.168896] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1387.171123] LDISKFS-fs (dm-1): recovery complete [ 1387.186813] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1387.523738] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1387.532587] Lustre: Skipped 4 previous similar messages [ 1387.557398] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1392.545827] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1392.706517] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:225) [ 1392.707109] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:225) [ 1403.891559] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 1405.829546] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1415.545882] Lustre: DEBUG MARKER: == replay-single test 110d: DNE: create striped dir, fail MDT2 and client ========================================================== 02:34:10 (1786689250) [ 1423.880988] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1426.245245] Lustre: Failing over lustre-MDT0001 [ 1426.452591] Lustre: server umount lustre-MDT0001 complete [ 1428.448629] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 1428.456327] LustreError: Skipped 1 previous similar message [ 1449.906754] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1449.909376] LDISKFS-fs (dm-1): recovery complete [ 1449.937858] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1455.254801] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1455.587227] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1455.597253] Lustre: Skipped 1 previous similar message [ 1465.041685] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 1467.517387] Lustre: lustre-MDT0001: Denying connection for new client 618cb24f-b021-4b09-adf6-73e9fe435baa (at 192.168.203.36@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:57 [ 1467.531104] Lustre: Skipped 1 previous similar message [ 1525.500349] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1525.505930] Lustre: 38846:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client fe3c5e73-a34f-43e2-9899-221e6938ec03@ [ 1525.524831] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1525.562208] Lustre: lustre-MDT0001: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 1525.564578] Lustre: lustre-MDT0001-osp-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1525.575595] Lustre: Skipped 1 previous similar message [ 1525.583295] Lustre: Skipped 12 previous similar messages [ 1525.640678] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:257) [ 1525.640846] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:257) [ 1538.337325] Lustre: DEBUG MARKER: == replay-single test 110e: DNE: create striped dir, uncommit on MDT2, fail client/MDT1/MDT2 ========================================================== 02:36:13 (1786689373) [ 1545.934540] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1553.910230] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1556.057508] Lustre: Failing over lustre-MDT0000 [ 1556.429767] Lustre: server umount lustre-MDT0000 complete [ 1557.989709] 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 [ 1557.998187] LustreError: 23934:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 1558.002830] Lustre: Skipped 12 previous similar messages [ 1558.041773] LustreError: 23934:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 169 previous similar messages [ 1560.427693] LustreError: 6497:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786689396 with bad export cookie 2724514938970144735 [ 1560.437545] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1560.440261] Lustre: Failing over lustre-MDT0001 [ 1560.445433] LustreError: 6497:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1560.883322] Lustre: server umount lustre-MDT0001 complete [ 1585.845289] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1585.855643] LDISKFS-fs (dm-0): recovery complete [ 1585.887316] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1586.001670] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1586.006778] LDISKFS-fs (dm-1): recovery complete [ 1586.035224] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1605.449370] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1605.465364] Lustre: Skipped 1 previous similar message [ 1610.974734] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1611.862317] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1612.168835] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1281) [ 1612.168948] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1281) [ 1618.399447] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786689399/real 1786689399] req@ffff8a3a4672f480 x1873478085376640/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786689454 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1621.468116] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 1623.921069] Lustre: lustre-MDT0001: Denying connection for new client 8b14f3de-5bf8-4eaa-9cbf-ae5a00a354dd (at 192.168.203.36@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:57 [ 1623.938279] Lustre: Skipped 11 previous similar messages [ 1681.500272] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1681.508241] Lustre: 41858:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 618cb24f-b021-4b09-adf6-73e9fe435baa@ [ 1681.517954] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1681.547248] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:289) [ 1681.548569] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:289) [ 1694.117457] Lustre: DEBUG MARKER: SKIP: replay-single test_110f skipping excluded test 110f [ 1696.239837] Lustre: DEBUG MARKER: == replay-single test 110g: DNE: create striped dir, uncommit on MDT1, fail client/MDT1/MDT2 ========================================================== 02:38:50 (1786689530) [ 1703.531593] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1711.842388] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1713.761130] Lustre: Failing over lustre-MDT0000 [ 1714.151489] Lustre: server umount lustre-MDT0000 complete [ 1714.664259] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1714.682236] LustreError: Skipped 2 previous similar messages [ 1717.984635] LustreError: 6498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786689554 with bad export cookie 2724514938970148907 [ 1717.988236] Lustre: Failing over lustre-MDT0001 [ 1717.989455] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1717.992453] LustreError: 6498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1718.428460] Lustre: server umount lustre-MDT0001 complete [ 1742.398291] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1742.404365] LDISKFS-fs (dm-1): recovery complete [ 1742.417094] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1742.502813] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1742.505428] LDISKFS-fs (dm-0): recovery complete [ 1742.512731] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1742.675643] LustreError: 45237:0:(llog.c:1655:llog_backup()) MGC192.168.203.136@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1742.683833] Lustre: 45237:0:(mgc_request_server.c:770:mgc_llog_local_copy()) MGC192.168.203.136@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1746.990492] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1747.006291] Lustre: Skipped 3 previous similar messages [ 1747.991641] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:321) [ 1747.992200] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:321) [ 1750.573376] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1750.829723] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1762.786614] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 1765.309594] Lustre: lustre-MDT0000: Denying connection for new client 41047010-d427-41ca-8b67-055148f8a1d3 (at 192.168.203.36@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:51 [ 1765.346757] Lustre: Skipped 11 previous similar messages [ 1816.500494] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1816.508786] Lustre: 45336:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 8b14f3de-5bf8-4eaa-9cbf-ae5a00a354dd@ [ 1816.529620] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1816.550909] Lustre: lustre-MDT0000: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 1816.562740] Lustre: Skipped 3 previous similar messages [ 1816.592071] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1313) [ 1816.593895] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1313) [ 1826.355271] Lustre: DEBUG MARKER: == replay-single test 111a: DNE: unlink striped dir, fail MDT1 ========================================================== 02:41:01 (1786689661) [ 1835.246822] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1837.684535] Lustre: Failing over lustre-MDT0000 [ 1837.968220] Lustre: server umount lustre-MDT0000 complete [ 1841.126803] LustreError: 6497:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786689677 with bad export cookie 2724514938970151553 [ 1858.017018] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1861.318297] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1861.320601] LDISKFS-fs (dm-0): recovery complete [ 1861.335981] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1868.280860] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28fa2b5 [ 1868.928416] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1868.947101] Lustre: Skipped 3 previous similar messages [ 1874.045698] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1345) [ 1874.048461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1345) [ 1874.530682] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1886.128863] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1887.968941] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1898.137123] Lustre: DEBUG MARKER: == replay-single test 111b: DNE: unlink striped dir, fail MDT2 ========================================================== 02:42:12 (1786689732) [ 1907.076021] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1909.504780] Lustre: Failing over lustre-MDT0001 [ 1909.816466] Lustre: server umount lustre-MDT0001 complete [ 1932.963937] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1932.972110] LDISKFS-fs (dm-1): recovery complete [ 1932.988203] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1933.340275] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1933.348077] Lustre: Skipped 6 previous similar messages [ 1938.128882] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1948.845779] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2008.501507] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 2008.514413] Lustre: 49523:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 41047010-d427-41ca-8b67-055148f8a1d3@ [ 2008.535122] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 2008.616765] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:353) [ 2008.625972] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:353) [ 2020.873201] Lustre: DEBUG MARKER: == replay-single test 111c: DNE: unlink striped dir, uncommit on MDT1, fail client/MDT1/MDT2 ========================================================== 02:44:15 (1786689855) [ 2028.934982] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2037.573810] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2039.680136] Lustre: Failing over lustre-MDT0000 [ 2040.195413] Lustre: server umount lustre-MDT0000 complete [ 2044.602956] Lustre: Failing over lustre-MDT0001 [ 2044.607022] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786689880 with bad export cookie 2724514938970153653 [ 2044.619752] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 2045.929677] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2045.944208] Lustre: Skipped 1 previous similar message [ 2049.962602] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2049.974665] Lustre: Skipped 1 previous similar message [ 2050.491372] Lustre: server umount lustre-MDT0001 complete [ 2076.523793] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2076.529098] LDISKFS-fs (dm-0): recovery complete [ 2076.538522] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2076.558230] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2076.563568] LDISKFS-fs (dm-1): recovery complete [ 2076.579906] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2076.789698] LustreError: 52482:0:(llog.c:1655:llog_backup()) MGC192.168.203.136@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 2076.796976] Lustre: 52482:0:(mgc_request_server.c:770:mgc_llog_local_copy()) MGC192.168.203.136@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 2089.953921] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28fae1c [ 2089.980916] Lustre: MGC192.168.203.136@tcp: Connection restored to 0@lo (at 0@lo) [ 2089.989216] Lustre: Skipped 20 previous similar messages [ 2095.419893] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2095.988140] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2096.566504] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:385) [ 2096.567164] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:385) [ 2106.099371] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2108.496250] Lustre: lustre-MDT0000: Denying connection for new client 092aeaf6-9a1f-4f83-b3d5-5c1dad883932 (at 192.168.203.36@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:58 [ 2108.519396] Lustre: Skipped 21 previous similar messages [ 2166.500944] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2166.516163] Lustre: 52576:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 08aab74c-2114-4142-93c8-933a9ff554e9@ [ 2166.536125] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2166.595487] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1377) [ 2166.604431] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1377) [ 2179.052729] Lustre: DEBUG MARKER: == replay-single test 111d: DNE: unlink striped dir, uncommit on MDT2, fail client/MDT1/MDT2 ========================================================== 02:46:54 (1786690014) [ 2186.787799] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2194.326140] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2196.543763] Lustre: Failing over lustre-MDT0000 [ 2196.859725] Lustre: server umount lustre-MDT0000 complete [ 2197.471781] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2197.484807] Lustre: Skipped 23 previous similar messages [ 2197.493245] LustreError: 8439:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 2197.511955] LustreError: 8439:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 73 previous similar messages [ 2200.440342] LustreError: 25692:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786690036 with bad export cookie 2724514938970156572 [ 2200.442741] Lustre: Failing over lustre-MDT0001 [ 2200.445159] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2200.445166] LustreError: Skipped 1 previous similar message [ 2200.457358] LustreError: 25692:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2200.727328] Lustre: server umount lustre-MDT0001 complete [ 2218.975959] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786690039/real 1786690039] req@ffff8a3b7c901f80 x1873478085701248/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786690055 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2219.031801] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 40 previous similar messages [ 2228.413795] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2228.424973] LDISKFS-fs (dm-0): recovery complete [ 2228.465761] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2228.520494] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2228.522580] LDISKFS-fs (dm-1): recovery complete [ 2228.550315] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2245.728820] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b6bca5500 x1873478085704448/t0(0) o250->MGC192.168.203.136@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 [ 2246.819914] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2246.840569] LustreError: Skipped 4 previous similar messages [ 2250.608898] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1409) [ 2250.609461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1409) [ 2252.792581] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2253.335011] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2263.953947] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2320.501459] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 2320.511036] Lustre: 55972:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 092aeaf6-9a1f-4f83-b3d5-5c1dad883932@ [ 2320.525713] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 2320.606886] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:417) [ 2320.608394] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:417) [ 2330.905398] Lustre: DEBUG MARKER: == replay-single test 111e: DNE: unlink striped dir, uncommit on MDT2, fail MDT1/MDT2 ========================================================== 02:49:25 (1786690165) [ 2338.566994] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2346.940529] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2349.064559] Lustre: Failing over lustre-MDT0000 [ 2349.526676] Lustre: server umount lustre-MDT0000 complete [ 2353.463576] Lustre: Failing over lustre-MDT0001 [ 2353.465501] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786690189 with bad export cookie 2724514938970158756 [ 2353.492528] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2353.894428] Lustre: server umount lustre-MDT0001 complete [ 2377.752664] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2377.755911] LDISKFS-fs (dm-0): recovery complete [ 2377.761673] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2378.029431] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2378.032186] LDISKFS-fs (dm-1): recovery complete [ 2378.046659] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2382.905498] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2382.947755] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2382.958131] Lustre: Skipped 7 previous similar messages [ 2383.349473] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2394.589069] Lustre: lustre-MDT0001: Recovery over after 0:12, of 2 clients 2 recovered and 0 were evicted. [ 2394.601813] Lustre: Skipped 6 previous similar messages [ 2394.655182] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:449) [ 2394.658480] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:449) [ 2394.685848] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1441) [ 2394.686647] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1441) [ 2399.979801] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2401.762128] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2403.797040] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2413.801928] Lustre: DEBUG MARKER: == replay-single test 111f: DNE: unlink striped dir, uncommit on MDT1, fail MDT1/MDT2 ========================================================== 02:50:48 (1786690248) [ 2422.850248] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2430.187636] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2432.101537] Lustre: Failing over lustre-MDT0000 [ 2432.327843] Lustre: server umount lustre-MDT0000 complete [ 2435.983915] Lustre: Failing over lustre-MDT0001 [ 2435.987417] LustreError: 6498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786690272 with bad export cookie 2724514938970161059 [ 2436.014136] LustreError: 6498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2436.455805] Lustre: server umount lustre-MDT0001 complete [ 2460.207282] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2460.212673] LDISKFS-fs (dm-1): recovery complete [ 2460.235307] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2460.257226] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2460.261261] LDISKFS-fs (dm-0): recovery complete [ 2460.271090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2460.485494] LustreError: 62732:0:(llog.c:1655:llog_backup()) MGC192.168.203.136@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 2460.493415] Lustre: 62732:0:(mgc_request_server.c:770:mgc_llog_local_copy()) MGC192.168.203.136@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 2461.153877] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28fc8be [ 2461.523552] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2461.539793] Lustre: Skipped 7 previous similar messages [ 2466.302385] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2466.792741] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2467.495362] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:481) [ 2467.496543] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:481) [ 2475.718545] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1473) [ 2475.720946] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1473) [ 2481.691892] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2483.524106] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2485.227474] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2495.532822] Lustre: DEBUG MARKER: == replay-single test 111g: DNE: unlink striped dir, fail MDT1/MDT2 ========================================================== 02:52:10 (1786690330) [ 2503.131482] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2510.698202] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2512.654919] Lustre: Failing over lustre-MDT0000 [ 2512.913623] Lustre: server umount lustre-MDT0000 complete [ 2516.706087] Lustre: Failing over lustre-MDT0001 [ 2516.706457] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786690352 with bad export cookie 2724514938970163390 [ 2516.737217] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2516.921370] Lustre: server umount lustre-MDT0001 complete [ 2540.663147] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2540.667897] LDISKFS-fs (dm-0): recovery complete [ 2540.689911] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2540.723716] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2540.733638] LDISKFS-fs (dm-1): recovery complete [ 2540.755061] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2540.947707] LustreError: 66209:0:(llog.c:1655:llog_backup()) MGC192.168.203.136@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 2540.952828] Lustre: 66209:0:(mgc_request_server.c:770:mgc_llog_local_copy()) MGC192.168.203.136@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 2541.024510] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3a4b16bb80 x1873478085875072/t0(0) o250->MGC192.168.203.136@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 [ 2541.319943] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2541.333077] Lustre: Skipped 8 previous similar messages [ 2545.873566] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2545.902378] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2548.262415] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:513) [ 2548.265773] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:513) [ 2557.579519] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1505) [ 2557.581282] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1505) [ 2563.886538] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2565.271243] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2567.084933] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2575.758745] Lustre: DEBUG MARKER: == replay-single test 112a: DNE: cross MDT rename, fail MDT1 ========================================================== 02:53:30 (1786690410) [ 2577.246403] Lustre: DEBUG MARKER: SKIP: replay-single test_112a needs >= 4 MDTs [ 2579.088598] Lustre: DEBUG MARKER: == replay-single test 112b: DNE: cross MDT rename, fail MDT2 ========================================================== 02:53:33 (1786690413) [ 2581.171334] Lustre: DEBUG MARKER: SKIP: replay-single test_112b needs >= 4 MDTs [ 2583.448388] Lustre: DEBUG MARKER: == replay-single test 112c: DNE: cross MDT rename, fail MDT3 ========================================================== 02:53:38 (1786690418) [ 2585.646594] Lustre: DEBUG MARKER: SKIP: replay-single test_112c needs >= 4 MDTs [ 2587.949712] Lustre: DEBUG MARKER: == replay-single test 112d: DNE: cross MDT rename, fail MDT4 ========================================================== 02:53:42 (1786690422) [ 2589.671080] Lustre: DEBUG MARKER: SKIP: replay-single test_112d needs >= 4 MDTs [ 2591.811289] Lustre: DEBUG MARKER: == replay-single test 112e: DNE: cross MDT rename, fail MDT1 and MDT2 ========================================================== 02:53:46 (1786690426) [ 2593.821174] Lustre: DEBUG MARKER: SKIP: replay-single test_112e needs >= 4 MDTs [ 2595.871304] Lustre: DEBUG MARKER: == replay-single test 112f: DNE: cross MDT rename, fail MDT1 and MDT3 ========================================================== 02:53:50 (1786690430) [ 2597.441639] Lustre: DEBUG MARKER: SKIP: replay-single test_112f needs >= 4 MDTs [ 2599.328442] Lustre: DEBUG MARKER: == replay-single test 112g: DNE: cross MDT rename, fail MDT1 and MDT4 ========================================================== 02:53:54 (1786690434) [ 2600.975986] Lustre: DEBUG MARKER: SKIP: replay-single test_112g needs >= 4 MDTs [ 2602.897308] Lustre: DEBUG MARKER: == replay-single test 112h: DNE: cross MDT rename, fail MDT2 and MDT3 ========================================================== 02:53:57 (1786690437) [ 2604.514258] Lustre: DEBUG MARKER: SKIP: replay-single test_112h needs >= 4 MDTs [ 2606.447403] Lustre: DEBUG MARKER: == replay-single test 112i: DNE: cross MDT rename, fail MDT2 and MDT4 ========================================================== 02:54:01 (1786690441) [ 2607.973468] Lustre: DEBUG MARKER: SKIP: replay-single test_112i needs >= 4 MDTs [ 2609.953598] Lustre: DEBUG MARKER: == replay-single test 112j: DNE: cross MDT rename, fail MDT3 and MDT4 ========================================================== 02:54:04 (1786690444) [ 2611.456708] Lustre: DEBUG MARKER: SKIP: replay-single test_112j needs >= 4 MDTs [ 2613.684213] Lustre: DEBUG MARKER: == replay-single test 112k: DNE: cross MDT rename, fail MDT1,MDT2,MDT3 ========================================================== 02:54:08 (1786690448) [ 2615.477570] Lustre: DEBUG MARKER: SKIP: replay-single test_112k needs >= 4 MDTs [ 2617.610825] Lustre: DEBUG MARKER: == replay-single test 112l: DNE: cross MDT rename, fail MDT1,MDT2,MDT4 ========================================================== 02:54:12 (1786690452) [ 2619.643371] Lustre: DEBUG MARKER: SKIP: replay-single test_112l needs >= 4 MDTs [ 2621.714839] Lustre: DEBUG MARKER: == replay-single test 112m: DNE: cross MDT rename, fail MDT1,MDT3,MDT4 ========================================================== 02:54:16 (1786690456) [ 2623.457820] Lustre: DEBUG MARKER: SKIP: replay-single test_112m needs >= 4 MDTs [ 2625.262837] Lustre: DEBUG MARKER: == replay-single test 112n: DNE: cross MDT rename, fail MDT2,MDT3,MDT4 ========================================================== 02:54:20 (1786690460) [ 2626.772202] Lustre: DEBUG MARKER: SKIP: replay-single test_112n needs >= 4 MDTs [ 2628.658211] Lustre: DEBUG MARKER: == replay-single test 115: failover for create/unlink striped directory ========================================================== 02:54:23 (1786690463) [ 2635.804593] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2638.519481] Lustre: Failing over lustre-MDT0001 [ 2638.918411] Lustre: server umount lustre-MDT0001 complete [ 2659.939300] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2659.941392] LDISKFS-fs (dm-1): recovery complete [ 2659.963265] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2664.993690] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2665.606386] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:545) [ 2665.614334] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:545) [ 2673.699128] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2674.979476] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2685.103210] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2688.156437] Lustre: Failing over lustre-MDT0000 [ 2688.470643] Lustre: server umount lustre-MDT0000 complete [ 2710.892446] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2710.901959] LDISKFS-fs (dm-0): recovery complete [ 2710.919616] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2717.667001] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e28fe48d [ 2717.680375] Lustre: MGC192.168.203.136@tcp: Connection restored to 0@lo (at 0@lo) [ 2717.683220] Lustre: Skipped 34 previous similar messages [ 2722.319699] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2723.445192] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1537) [ 2723.446176] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1537) [ 2731.593544] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2733.512426] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2743.801627] Lustre: DEBUG MARKER: == replay-single test 116a: large update log master MDT recovery ========================================================== 02:56:18 (1786690578) [ 2751.562441] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2752.479765] Lustre: *** cfs_fail_loc=1702, val=0*** [ 2754.707835] Lustre: Failing over lustre-MDT0000 [ 2754.972934] Lustre: server umount lustre-MDT0000 complete [ 2775.519361] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786690595/real 1786690595] req@ffff8a3b7d8c0380 x1873478086048256/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786690611 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2775.556867] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 47 previous similar messages [ 2775.575034] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2775.586816] LustreError: Skipped 4 previous similar messages [ 2776.855478] LDISKFS-fs (dm-0): 4 truncates cleaned up [ 2776.864389] LDISKFS-fs (dm-0): recovery complete [ 2776.882929] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2790.487740] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2791.573672] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1569) [ 2791.580935] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1569) [ 2800.025659] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2801.493433] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2809.912581] Lustre: DEBUG MARKER: == replay-single test 116b: large update log slave MDT recovery ========================================================== 02:57:24 (1786690644) [ 2817.089995] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2818.157725] Lustre: *** cfs_fail_loc=1702, val=0*** [ 2820.571978] Lustre: Failing over lustre-MDT0001 [ 2820.909550] Lustre: server umount lustre-MDT0001 complete [ 2822.111947] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2822.118513] LustreError: 66218:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: 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. [ 2822.127094] Lustre: Skipped 35 previous similar messages [ 2822.147776] LustreError: 66218:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 116 previous similar messages [ 2841.948752] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2841.956450] LDISKFS-fs (dm-1): recovery complete [ 2841.970580] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2845.866275] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2847.278513] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:577) [ 2847.280181] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:577) [ 2855.525335] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 2857.293507] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2866.442410] Lustre: DEBUG MARKER: == replay-single test 117: DNE: cross MDT unlink, fail MDT1 and MDT2 ========================================================== 02:58:21 (1786690701) [ 2868.169793] Lustre: DEBUG MARKER: SKIP: replay-single test_117 needs >= 4 MDTs [ 2870.123384] Lustre: DEBUG MARKER: == replay-single test 118: invalidate osp update will not cause update log corruption ========================================================== 02:58:24 (1786690704) [ 2871.799839] Lustre: *** cfs_fail_loc=1705, val=0*** [ 2880.108368] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2882.287937] Lustre: Failing over lustre-MDT0000 [ 2882.542741] Lustre: server umount lustre-MDT0000 complete [ 2905.510890] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 2905.521526] LDISKFS-fs (dm-0): recovery complete [ 2905.529533] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2914.385939] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2915.060813] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1601) [ 2915.064405] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1601) [ 2924.287883] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2925.663591] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2934.326977] Lustre: DEBUG MARKER: == replay-single test 119: timeout of normal replay does not cause DNE replay fails ========================================================== 02:59:29 (1786690769) [ 2941.953388] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2945.273330] Lustre: Failing over lustre-MDT0000 [ 2945.572736] Lustre: server umount lustre-MDT0000 complete [ 2960.508518] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 2960.510973] LDISKFS-fs (dm-0): recovery complete [ 2960.523609] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2960.901229] Lustre: 66222:0:(ldlm_lib.c:2085:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 0 [ 2965.045348] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2965.991838] Lustre: 8439:0:(ldlm_lib.c:2085:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 0 [ 2966.019071] LustreError: 79909:0:(ldlm_lib.c:2690:replay_request_or_update()) cfs_fail_timeout id 714 sleeping for 65000ms [ 2972.558550] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3031.063094] LustreError: 79909:0:(ldlm_lib.c:2690:replay_request_or_update()) cfs_fail_timeout id 714 awake [ 3031.076560] Lustre: 79909:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp [ 3031.084645] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3031.088394] Lustre: 79909:0:(ldlm_lib.c:1914:abort_req_replay_queue()) @@@ aborted: req@ffff8a3b523e9500 x1873478068584448/t0(81604378629) o36->81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp:744/0 lens 528/0 e 7 to 0 dl 1786690879 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3031.104727] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 3031.109273] Lustre: 79909:0:(ldlm_lib.c:2085:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 1 [ 3031.135678] Lustre: lustre-MDT0000: Denying connection for new client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 1 evicted) already passed deadline 0:10 [ 3031.153485] Lustre: Skipped 22 previous similar messages [ 3031.202748] Lustre: 79909:0:(ldlm_lib.c:2394:target_recovery_overseer()) lustre-MDT0000 recovery is aborted by hard timeout [ 3031.207790] Lustre: 79909:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3031.216925] Lustre: 79909:0:(ldlm_lib.c:2404:target_recovery_overseer()) Skipped 2 previous similar messages [ 3031.230826] Lustre: lustre-MDT0000-osd: cancel update llog [0x200001b70:0x1:0x0] [ 3031.243859] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240002b11:0x1:0x0] [ 3031.259737] Lustre: 79909:0:(ldlm_lib.c:2951:target_recovery_thread()) too long recovery - read logs [ 3031.276033] LustreError: dumping log to /tmp/lustre-log.1786690867.79909 [ 3031.373395] Lustre: lustre-MDT0000: Recovery over after 1:11, of 2 clients 1 recovered and 1 was evicted. [ 3031.379629] Lustre: Skipped 10 previous similar messages [ 3031.414536] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1633) [ 3031.415065] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1633) [ 3035.898105] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 56 sec [ 3049.134451] Lustre: DEBUG MARKER: == replay-single test 120: DNE fail abort should stop both normal and DNE replay ========================================================== 03:01:23 (1786690883) [ 3056.192046] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3062.777285] Lustre: Failing over lustre-MDT0000 [ 3063.097228] Lustre: server umount lustre-MDT0000 complete [ 3077.051788] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3077.057486] LDISKFS-fs (dm-0): recovery complete [ 3077.064794] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3077.517294] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3077.517782] Lustre: lustre-MDT0000: Aborting client recovery [ 3077.527576] Lustre: Skipped 9 previous similar messages [ 3077.531248] LustreError: 81882:0:(ldlm_lib.c:3004:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3077.542866] Lustre: 81916:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3077.547984] Lustre: 81916:0:(ldlm_lib.c:2404:target_recovery_overseer()) Skipped 1 previous similar message [ 3077.557142] Lustre: lustre-MDT0000-osd: cancel update llog [0x200009870:0x3:0x0] [ 3077.567477] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x2400090a2:0x1:0x0] [ 3077.605664] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1665) [ 3077.611799] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1665) [ 3082.565705] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3082.745554] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 3105.319634] Lustre: DEBUG MARKER: == replay-single test 121: lock replay timed out and race ========================================================== 03:02:20 (1786690940) [ 3108.827855] Lustre: Failing over lustre-MDT0000 [ 3109.282035] Lustre: server umount lustre-MDT0000 complete [ 3113.442363] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3113.453645] LustreError: Skipped 6 previous similar messages [ 3113.954462] Lustre: *** cfs_fail_loc=721, val=0*** [ 3113.958778] Lustre: Skipped 7 previous similar messages [ 3114.499947] Lustre: *** cfs_fail_loc=721, val=0*** [ 3114.503726] Lustre: Skipped 2 previous similar messages [ 3118.561149] Lustre: *** cfs_fail_loc=721, val=0*** [ 3118.570491] Lustre: Skipped 7 previous similar messages [ 3121.056370] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3121.272227] Lustre: *** cfs_fail_loc=721, val=0*** [ 3121.281605] Lustre: Skipped 5 previous similar messages [ 3124.748340] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3124.753570] Lustre: Skipped 10 previous similar messages [ 3125.906450] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3126.090735] Lustre: *** cfs_fail_loc=721, val=1*** [ 3126.098754] Lustre: Skipped 85 previous similar messages [ 3126.775508] Lustre: *** cfs_fail_loc=721, val=1*** [ 3126.783254] Lustre: Skipped 6 previous similar messages [ 3134.431739] Lustre: *** cfs_fail_loc=721, val=1*** [ 3134.438413] Lustre: Skipped 43 previous similar messages [ 3141.129849] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:53 [ 3151.364496] Lustre: *** cfs_fail_loc=721, val=1*** [ 3151.370583] Lustre: Skipped 60 previous similar messages [ 3156.959789] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3156.964413] Lustre: *** cfs_fail_loc=721, val=1*** [ 3156.978992] Lustre: 83338:0:(tgt_handler.c:581:tgt_handle_recovery()) @@@ obsoleted, rq_xid=1873478068726400, exp_last_xid=1873478068728191 req@ffff8a3b7ee81500 x1873478068726400/t0(0) o101->81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp:0/0 lens 328/0 e 0 to 0 dl 1786690971 ref 1 fl Complete:/240/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 3157.517120] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:36 [ 3172.883517] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:21 [ 3185.631879] Lustre: *** cfs_fail_loc=721, val=1*** [ 3185.641706] Lustre: Skipped 134 previous similar messages [ 3187.169540] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3187.178708] Lustre: *** cfs_fail_loc=721, val=1*** [ 3187.180848] Lustre: 83338:0:(tgt_handler.c:581:tgt_handle_recovery()) @@@ obsoleted, rq_xid=1873478068726272, exp_last_xid=1873478068728191 req@ffff8a3b7ee81880 x1873478068726272/t0(0) o101->81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp:0/0 lens 328/0 e 0 to 0 dl 1786690971 ref 1 fl Complete:/240/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 3189.264875] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:18 [ 3204.623899] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:02 [ 3217.379077] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3217.406885] Lustre: *** cfs_fail_loc=721, val=1*** [ 3217.409542] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 3221.078137] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:26 [ 3237.390749] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:10 [ 3247.587714] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3247.599795] Lustre: *** cfs_fail_loc=721, val=1*** [ 3247.605758] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 3252.191789] Lustre: *** cfs_fail_loc=721, val=1*** [ 3252.195962] Lustre: Skipped 260 previous similar messages [ 3277.791878] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3277.812895] Lustre: *** cfs_fail_loc=721, val=1*** [ 3285.527162] Lustre: lustre-MDT0000: Client 81ea5a2f-28f2-45a7-9448-c2e7083ea547 (at 192.168.203.36@tcp) reconnected, waiting for 2 clients in recovery for 0:12 [ 3285.542573] Lustre: Skipped 2 previous similar messages [ 3300.867401] Lustre: lustre-MDT0000: Recovery already passed deadline 0:02. If you do not want to wait more, you may force taget eviction via 'lctl --device lustre-MDT0000 abort_recovery. [ 3308.000160] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 3308.015508] Lustre: 83338:0:(ldlm_lib.c:2085:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 3308.037994] Lustre: 83338:0:(ldlm_lib.c:2085:extend_recovery_timer()) Skipped 20 previous similar messages [ 3308.058357] Lustre: 83338:0:(ldlm_lib.c:2394:target_recovery_overseer()) lustre-MDT0000 recovery is aborted by hard timeout [ 3308.071688] Lustre: 83338:0:(ldlm_lib.c:2394:target_recovery_overseer()) Skipped 1 previous similar message [ 3308.082364] Lustre: 83338:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3308.092352] Lustre: 83338:0:(ldlm_lib.c:2404:target_recovery_overseer()) Skipped 2 previous similar messages [ 3308.101955] Lustre: 83338:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp [ 3308.124341] Lustre: 83338:0:(genops.c:1622:class_disconnect_stale_exports()) Skipped 2 previous similar messages [ 3308.138914] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3308.147979] Lustre: Skipped 1 previous similar message [ 3308.153653] LustreError: 83338:0:(ldlm_lib.c:1934:abort_lock_replay_queue()) @@@ aborted: req@ffff8a3b43573800 x1873478068733056/t0(0) o101->81ea5a2f-28f2-45a7-9448-c2e7083ea547@192.168.203.36@tcp:0/0 lens 328/0 e 0 to 0 dl 1786691019 ref 1 fl Complete:/240/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 3308.185528] Lustre: lustre-MDT0000-osd: cancel update llog [0x20000a040:0x1:0x0] [ 3308.202692] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x2400090a3:0x1:0x0] [ 3308.229818] Lustre: 83338:0:(ldlm_lib.c:2951:target_recovery_thread()) too long recovery - read logs [ 3308.239477] LustreError: dumping log to /tmp/lustre-log.1786691144.83338 [ 3308.380768] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1667 to 0x280000401:1697) [ 3308.381668] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1697) [ 3325.701820] Lustre: DEBUG MARKER: == replay-single test 130a: DoM file create (setstripe) replay ========================================================== 03:06:00 (1786691160) [ 3333.692157] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3335.663847] Lustre: Failing over lustre-MDT0000 [ 3335.959984] Lustre: server umount lustre-MDT0000 complete [ 3358.432315] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3358.436807] LDISKFS-fs (dm-0): recovery complete [ 3358.448876] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3365.352193] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e2903457 [ 3365.362919] Lustre: MGC192.168.203.136@tcp: Connection restored to 0@lo (at 0@lo) [ 3365.373869] Lustre: Skipped 27 previous similar messages [ 3365.601989] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3365.606541] Lustre: Skipped 9 previous similar messages [ 3369.626650] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3371.170661] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1667 to 0x280000401:1729) [ 3371.181347] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1729) [ 3379.212851] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3380.739592] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3388.882401] Lustre: DEBUG MARKER: == replay-single test 130b: DoM file create (inherited) replay ========================================================== 03:07:03 (1786691223) [ 3397.096100] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3399.470809] Lustre: Failing over lustre-MDT0000 [ 3399.664044] Lustre: server umount lustre-MDT0000 complete [ 3417.058134] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786691237/real 1786691237] req@ffff8a3a41ed1c00 x1873478086448000/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786691253 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3417.093519] Lustre: 3640:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 3417.112283] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3417.141418] LustreError: Skipped 5 previous similar messages [ 3422.153991] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3422.159231] LDISKFS-fs (dm-0): recovery complete [ 3422.179407] LustreError: 72029:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 3422.186733] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3422.196892] LustreError: 72029:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 146 previous similar messages [ 3427.297465] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b523e7480 x1873478086456576/t0(0) o250->MGC192.168.203.136@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 [ 3431.945865] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3433.157722] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1667 to 0x280000401:1761) [ 3433.166351] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1761) [ 3441.532990] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3443.156369] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3452.515317] Lustre: DEBUG MARKER: == replay-single test 131a: DoM file write lock replay === 03:08:07 (1786691287) [ 3460.492575] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3462.506259] Lustre: Failing over lustre-MDT0000 [ 3462.770552] Lustre: server umount lustre-MDT0000 complete [ 3463.650537] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3463.669630] Lustre: Skipped 26 previous similar messages [ 3485.316840] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3485.318907] LDISKFS-fs (dm-0): recovery complete [ 3485.347341] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3495.347798] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3496.025552] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1667 to 0x280000401:1793) [ 3496.029202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1793) [ 3505.460473] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3507.018363] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3515.272456] Lustre: DEBUG MARKER: SKIP: replay-single test_131b skipping excluded test 131b [ 3517.046536] Lustre: DEBUG MARKER: == replay-single test 132a: PFL new component instantiate replay ========================================================== 03:09:11 (1786691351) [ 3524.559055] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3526.858017] Lustre: Failing over lustre-MDT0000 [ 3527.153092] Lustre: server umount lustre-MDT0000 complete [ 3550.394753] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3550.397816] LDISKFS-fs (dm-0): recovery complete [ 3550.414649] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3557.352035] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e29045a6 [ 3563.116664] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1825) [ 3563.122146] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1825) [ 3563.534627] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3573.352693] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3575.260865] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3584.562815] Lustre: DEBUG MARKER: == replay-single test 133: check resend of ongoing requests for lwp during failover ========================================================== 03:10:19 (1786691419) [ 3589.182481] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 3589.188534] Lustre: Skipped 280 previous similar messages [ 3591.806770] Lustre: Failing over lustre-MDT0000 [ 3592.170934] Lustre: server umount lustre-MDT0000 complete [ 3605.515610] Lustre: lustre-MDT0001: Client 59e1b146-97c1-4ec4-a285-e4a5f99d5643 (at 192.168.203.36@tcp) reconnecting [ 3612.463775] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3619.295871] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b7ba07800 x1873478086563584/t0(0) o250->MGC192.168.203.136@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 [ 3623.318610] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3624.947258] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000300000400-0x0000000340000400]:1:mdt [ 3624.953963] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000300000400-0x0000000340000400]:1:mdt] [ 3625.009673] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1857) [ 3625.013433] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1857) [ 3631.982978] Lustre: DEBUG MARKER: == replay-single test 134: replay creation of a file created in a pool ========================================================== 03:11:07 (1786691467) [ 3647.532744] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3649.428192] Lustre: Failing over lustre-MDT0000 [ 3649.672822] Lustre: server umount lustre-MDT0000 complete [ 3671.615578] LDISKFS-fs (dm-0): 4 truncates cleaned up [ 3671.619025] LDISKFS-fs (dm-0): recovery complete [ 3671.629048] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3680.793093] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3681.821545] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 3681.827039] Lustre: Skipped 6 previous similar messages [ 3681.869336] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1889) [ 3681.873458] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1889) [ 3690.207369] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3691.710906] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3709.553358] Lustre: DEBUG MARKER: == replay-single test 135: Server failure in lock replay phase ========================================================== 03:12:24 (1786691544) [ 3719.307624] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 3721.475151] Lustre: Failing over lustre-OST0000 [ 3722.726985] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3722.733515] Lustre: Skipped 1 previous similar message [ 3723.644662] Lustre: server umount lustre-OST0000 complete [ 3730.064399] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing load_module ../libcfs/libcfs/libcfs [ 3742.444504] LDISKFS-fs (dm-2): 3 truncates cleaned up [ 3742.446546] LDISKFS-fs (dm-2): recovery complete [ 3742.460340] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3742.653076] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3742.667702] Lustre: Skipped 9 previous similar messages [ 3743.242176] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3743.255786] Lustre: Skipped 6 previous similar messages [ 3744.048969] Lustre: *** cfs_fail_loc=32d, val=20*** [ 3744.056174] Lustre: Skipped 1 previous similar message [ 3749.121629] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3757.170700] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount REPLAY_LOCKS osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 3759.059295] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in REPLAY_LOCKS state after 0 sec [ 3759.702132] Lustre: lustre-OST0000: Client 59e1b146-97c1-4ec4-a285-e4a5f99d5643 (at 192.168.203.36@tcp) reconnected, waiting for 3 clients in recovery for 1:24 [ 3761.121671] Lustre: Failing over lustre-OST0000 [ 3761.131262] LustreError: 97753:0:(ldlm_lib.c:3004:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 3761.141467] Lustre: 96971:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3761.148744] LustreError: 96971:0:(ofd_obd.c:1324:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 3761.337281] Lustre: server umount lustre-OST0000 complete [ 3779.392370] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing load_module ../libcfs/libcfs/libcfs [ 3785.841248] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3792.266758] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3796.464062] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3796.471612] Lustre: Skipped 2 previous similar messages [ 3801.570176] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3801.576258] Lustre: Skipped 2 previous similar messages [ 3806.694340] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3806.709521] Lustre: Skipped 2 previous similar messages [ 3810.271153] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3810.380372] Lustre: server umount lustre-OST0000 complete [ 3815.393209] LustreError: lustre-OST0001-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3815.397221] Lustre: lustre-OST0001: Not available for connect from 0@lo (stopping) [ 3815.406448] LustreError: Skipped 4 previous similar messages [ 3815.413979] Lustre: Skipped 1 previous similar message [ 3820.836803] Lustre: server umount lustre-OST0001 complete [ 3829.768365] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3837.737793] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3847.327818] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3848.549346] LustreError: lustre-OST0000-osc-MDT0001: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 3848.574156] LustreError: lustre-OST0001-osc-MDT0001: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3848.598356] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 3848.630242] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3853.980109] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3865.501495] Lustre: DEBUG MARKER: == replay-single test 136: MDS to disconnect all OSPs first, then cleanup ldlm ========================================================== 03:15:00 (1786691700) [ 3867.104682] Lustre: DEBUG MARKER: SKIP: replay-single test_136 needs > 2 MDTs [ 3868.830267] Lustre: DEBUG MARKER: == replay-single test 137a: DNE: create under striped dir, fail MDT1 ========================================================== 03:15:03 (1786691703) [ 3876.139356] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3878.014470] Lustre: Failing over lustre-MDT0000 [ 3878.269757] Lustre: server umount lustre-MDT0000 complete [ 3901.222180] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3901.224328] LDISKFS-fs (dm-0): recovery complete [ 3901.231478] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3904.997446] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e2906ef7 [ 3909.863729] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3910.790773] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1921) [ 3910.798313] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1911 to 0x280000401:1953) [ 3919.555657] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3921.242512] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3932.051830] Lustre: DEBUG MARKER: == replay-single test 137b: DNE: create under striped dir, fail MDT2 ========================================================== 03:16:06 (1786691766) [ 3940.826901] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 3943.258149] Lustre: Failing over lustre-MDT0001 [ 3943.809927] Lustre: server umount lustre-MDT0001 complete [ 3965.615444] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 3965.620775] LDISKFS-fs (dm-1): recovery complete [ 3965.633213] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3965.953286] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3965.961022] Lustre: Skipped 10 previous similar messages [ 3969.918715] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3971.054709] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3971.063781] Lustre: Skipped 36 previous similar messages [ 3971.174919] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:580 to 0x2c0000400:609) [ 3971.175155] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:579 to 0x280000400:609) [ 3980.687756] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 3982.455328] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3992.507661] Lustre: DEBUG MARKER: == replay-single test 137c: DNE: create under striped dir, fail MDT1/MDT2 ========================================================== 03:17:07 (1786691827) [ 4000.936925] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4008.593935] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 4010.737472] Lustre: Failing over lustre-MDT0001 [ 4011.069996] Lustre: server umount lustre-MDT0001 complete [ 4014.656914] Lustre: Failing over lustre-MDT0000 [ 4015.096801] Lustre: server umount lustre-MDT0000 complete [ 4033.503260] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786691853/real 1786691853] req@ffff8a3b6bccdf80 x1873478086843008/t0(0) o400->MGC192.168.203.136@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786691869 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4033.581286] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 4033.605811] LustreError: MGC192.168.203.136@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4033.644140] LustreError: Skipped 5 previous similar messages [ 4041.455624] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 4041.457387] LDISKFS-fs (dm-1): recovery complete [ 4041.458323] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 4041.473353] LDISKFS-fs (dm-0): recovery complete [ 4041.477397] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4041.497085] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4041.632982] LustreError: 107311:0:(llog.c:1655:llog_backup()) MGC192.168.203.136@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 4041.637350] Lustre: 107311:0:(mgc_request_server.c:770:mgc_llog_local_copy()) MGC192.168.203.136@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 4043.615337] LustreError: 107309:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 4043.630087] LustreError: 107309:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8a3b6bccce00 x1873478086845440/t0(0) o250->MGC192.168.203.136@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786691879 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4043.650548] LustreError: 107309:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 4043.808559] LustreError: 107318:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: 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. [ 4043.825649] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x25cf6be6e2907e24 [ 4043.843702] LustreError: 107318:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 217 previous similar messages [ 4048.745911] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4048.992902] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4050.719174] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1911 to 0x280000401:1985) [ 4050.721164] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1953) [ 4053.870103] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:579 to 0x280000400:641) [ 4053.874218] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:580 to 0x2c0000400:641) [ 4059.478863] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [ 4060.914312] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4062.555849] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4072.178032] Lustre: DEBUG MARKER: == replay-single test 200: Dropping one OBD_PING should not cause disconnect ========================================================== 03:18:26 (1786691906) [ 4073.797396] Lustre: DEBUG MARKER: SKIP: replay-single test_200 Need remote client [ 4076.083216] Lustre: DEBUG MARKER: == replay-single test 201: MDT umount cascading disconnects timeouts ========================================================== 03:18:30 (1786691910) [ 4081.117202] LustreError: 108685:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 4084.742550] LustreError: 101119:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 4084.753413] LustreError: 101119:0:(tgt_handler.c:1143:tgt_disconnect()) Skipped 1 previous similar message [ 4089.143791] LustreError: 108685:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 awake [ 4089.164451] Lustre: Failing over lustre-MDT0001 [ 4089.171289] LustreError: 108392:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 4089.828070] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4089.841599] Lustre: Skipped 32 previous similar messages [ 4089.849995] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4089.854858] Lustre: Skipped 4 previous similar messages [ 4092.775113] LustreError: 100575:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 awake [ 4092.792256] LustreError: 100575:0:(tgt_handler.c:1143:tgt_disconnect()) Skipped 1 previous similar message [ 4097.215118] LustreError: 99687:0:(tgt_handler.c:1143:tgt_disconnect()) cfs_fail_timeout id 245 awake [ 4097.229886] LustreError: 99687:0:(tgt_handler.c:1143:tgt_disconnect()) Skipped 2 previous similar messages [ 4097.388813] Lustre: server umount lustre-MDT0001 complete [ 4109.297601] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4115.020795] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:579 to 0x280000400:673) [ 4115.022764] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:580 to 0x2c0000400:673) [ 4115.725971] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4125.342561] Lustre: DEBUG MARKER: == replay-single test 202: pfl replay should recovery layout generation ========================================================== 03:19:19 (1786691959) [ 4133.765871] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4135.789070] Lustre: Failing over lustre-MDT0000 [ 4135.947055] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.36@tcp (stopping) [ 4135.954051] Lustre: Skipped 8 previous similar messages [ 4136.122938] Lustre: server umount lustre-MDT0000 complete [ 4158.656200] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 4158.659451] LDISKFS-fs (dm-0): recovery complete [ 4158.669285] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4166.628326] LustreError: 3639:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a3b523ead80 x1873478086923904/t0(0) o250->MGC192.168.203.136@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 [ 4171.665758] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4172.471952] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1955 to 0x2c0000401:1985) [ 4172.472495] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1911 to 0x280000401:2017) [ 4181.265634] Lustre: DEBUG MARKER: oleg336-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4182.871629] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4191.951783] Lustre: DEBUG MARKER: == replay-single test 203: resend can hit original request ========================================================== 03:20:26 (1786692026) [ 4193.714757] LustreError: 108685:0:(mdt_handler.c:2126:mdt_getattr_name_lock()) cfs_fail_timeout id 2403 sleeping for 2000ms [ 4193.734468] LustreError: 108685:0:(mdt_handler.c:2126:mdt_getattr_name_lock()) Skipped 2 previous similar messages [ 4195.751092] LustreError: 108685:0:(mdt_handler.c:2126:mdt_getattr_name_lock()) cfs_fail_timeout id 2403 awake [ 4195.769361] Lustre: 108685:0:(service.c:2628:ptlrpc_server_handle_request()) @@@ pause req after reply req@ffff8a3a49629880 x1873478069042048/t0(0) o101->59e1b146-97c1-4ec4-a285-e4a5f99d5643@192.168.203.36@tcp:434/0 lens 592/1888 e 0 to 0 dl 1786692079 ref 1 fl Complete:/600/0 rc 0/0 job:'stat.0' uid:0 gid:0 projid:0 [ 4198.816816] Lustre: 108685:0:(service.c:2630:ptlrpc_server_handle_request()) @@@ continue req@ffff8a3a49629880 x1873478069042048/t0(0) o101->59e1b146-97c1-4ec4-a285-e4a5f99d5643@192.168.203.36@tcp:434/0 lens 592/1888 e 0 to 0 dl 1786692079 ref 1 fl Complete:/600/0 rc 0/0 job:'stat.0' uid:0 gid:0 projid:0 [ 4205.455818] Lustre: DEBUG MARKER: == replay-single test complete, duration 3923 sec ======== 03:20:40 (1786692040) [ 4207.320229] Lustre: DEBUG MARKER: === replay-single: start cleanup 03:20:42 (1786692042) === [ 4215.924562] Lustre: DEBUG MARKER: === replay-single: finish cleanup 03:20:50 (1786692050) === [ 4220.245692] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4226.657446] Lustre: server umount lustre-MDT0000 complete [ 4237.383270] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786692073 with bad export cookie 2724514938970213237 [ 4237.391364] LustreError: 26175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4237.816296] Lustre: server umount lustre-MDT0001 complete [ 4257.730343] Lustre: server umount lustre-OST0000 complete [ 4276.972784] Lustre: server umount lustre-OST0001 complete [ 4296.290560] Lustre: DEBUG MARKER: oleg336-server.virtnet: executing unload_modules_local [ 4299.376907] Key type lgssc unregistered [ 4299.726693] LNet: 114615:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4299.736445] LNetError: 114615:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4299.765082] LNet: Removed LNI 192.168.203.136@tcp [ 4300.793188] Key type .llcrypt unregistered [ 4300.794951] Key type ._llcrypt unregistered