[ 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-8.fc42 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 548870723 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 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 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, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002339] x2apic enabled [ 0.003018] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006970] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007030] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008018] pid_max: default: 32768 minimum: 301 [ 0.010113] LSM: Security Framework initializing [ 0.011051] Yama: becoming mindful. [ 0.012033] SELinux: Initializing. [ 0.013060] *** VALIDATE selinux *** [ 0.021285] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025423] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026199] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027121] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028101] *** VALIDATE tmpfs *** [ 0.029492] *** VALIDATE proc *** [ 0.030233] *** VALIDATE cgroup *** [ 0.031008] *** VALIDATE cgroup2 *** [ 0.032204] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.033134] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.034005] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.035035] Spectre V2 : User space: Vulnerable [ 0.036010] Speculative Store Bypass: Vulnerable [ 0.039402] debug: unmapping init [mem 0xffffffffb1e59000-0xffffffffb1e60fff] [ 0.042000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042810] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043027] ... version: 2 [ 0.044014] ... bit width: 48 [ 0.045016] ... generic registers: 4 [ 0.046015] ... value mask: 0000ffffffffffff [ 0.047016] ... max period: 00007fffffffffff [ 0.048014] ... fixed-purpose events: 3 [ 0.048947] ... event mask: 000000070000000f [ 0.049258] rcu: Hierarchical SRCU implementation. [ 0.051341] smp: Bringing up secondary CPUs ... [ 0.052473] x86: Booting SMP configuration: [ 0.053025] .... node #0, CPUs: #1 #2 #3 [ 0.056081] smp: Brought up 1 node, 4 CPUs [ 0.057880] smpboot: Max logical packages: 1 [ 0.058015] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.132530] node 0 deferred pages initialised in 71ms [ 0.134112] devtmpfs: initialized [ 0.135190] x86/mm: Memory block size: 128MB [ 0.137588] gcov: version magic: 0x41383552 [ 0.139292] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.140093] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.141254] pinctrl core: initialized pinctrl subsystem [ 0.142185] [ 0.142468] ************************************************************* [ 0.143014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.144008] ** ** [ 0.145008] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.146009] ** ** [ 0.147009] ** This means that this kernel is built to expose internal ** [ 0.148007] ** IOMMU data structures, which may compromise security on ** [ 0.149011] ** your system. ** [ 0.150008] ** ** [ 0.151010] ** If you see this message and you are not debugging the ** [ 0.152009] ** kernel, report this immediately to your vendor! ** [ 0.153013] ** ** [ 0.154008] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.155011] ************************************************************* [ 0.156683] NET: Registered protocol family 16 [ 0.157370] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.158069] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.159063] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.160508] cpuidle: using governor menu [ 0.161404] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.164475] PCI: Using configuration type 1 for base access [ 0.166101] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.176049] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.177023] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.178151] cryptd: max_cpu_qlen set to 1000 [ 0.181010] ACPI: Added _OSI(Module Device) [ 0.182018] ACPI: Added _OSI(Processor Device) [ 0.184016] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.186013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.191445] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.197632] ACPI: Interpreter enabled [ 0.199068] ACPI: PM: (supports S0 S3 S4 S5) [ 0.201017] ACPI: Using IOAPIC for interrupt routing [ 0.203161] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.206389] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.215999] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.218046] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.221020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.224071] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.227459] acpiphp: Slot [2] registered [ 0.229094] acpiphp: Slot [5] registered [ 0.230075] acpiphp: Slot [6] registered [ 0.231032] acpiphp: Slot [7] registered [ 0.232039] acpiphp: Slot [8] registered [ 0.232811] acpiphp: Slot [9] registered [ 0.233080] acpiphp: Slot [10] registered [ 0.233937] acpiphp: Slot [3] registered [ 0.235079] acpiphp: Slot [4] registered [ 0.236047] acpiphp: Slot [11] registered [ 0.236949] acpiphp: Slot [12] registered [ 0.238097] acpiphp: Slot [13] registered [ 0.239112] acpiphp: Slot [14] registered [ 0.241098] acpiphp: Slot [15] registered [ 0.242095] acpiphp: Slot [16] registered [ 0.244093] acpiphp: Slot [17] registered [ 0.245106] acpiphp: Slot [18] registered [ 0.246132] acpiphp: Slot [19] registered [ 0.248087] acpiphp: Slot [20] registered [ 0.249082] acpiphp: Slot [21] registered [ 0.250095] acpiphp: Slot [22] registered [ 0.251119] acpiphp: Slot [23] registered [ 0.253099] acpiphp: Slot [24] registered [ 0.254110] acpiphp: Slot [25] registered [ 0.255072] acpiphp: Slot [26] registered [ 0.256000] acpiphp: Slot [27] registered [ 0.258129] acpiphp: Slot [28] registered [ 0.260115] acpiphp: Slot [29] registered [ 0.260915] acpiphp: Slot [30] registered [ 0.261065] acpiphp: Slot [31] registered [ 0.261883] PCI host bridge to bus 0000:00 [ 0.263017] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.265023] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.267022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.269017] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.270016] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.271024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.272186] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.275145] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.279393] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.288792] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.293454] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.295018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.297016] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.299015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.301563] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.303762] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.307046] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.309844] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.315021] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.326017] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.332016] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.337000] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.342019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.350024] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.367026] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.376834] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.393029] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.399019] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.417022] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.426778] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.432018] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.437022] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.454039] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.463174] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.470025] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.477026] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.493030] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.504847] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.509023] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.515027] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.526949] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.533876] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.540015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.544017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.555022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.564955] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.569405] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.572424] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.575572] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.579279] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.584090] iommu: Default domain type: Passthrough [ 0.585359] SCSI subsystem initialized [ 0.587119] ACPI: bus type USB registered [ 0.588077] usbcore: registered new interface driver usbfs [ 0.589083] usbcore: registered new interface driver hub [ 0.590075] usbcore: registered new device driver usb [ 0.591124] pps_core: LinuxPPS API ver. 1 registered [ 0.592007] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.594047] PTP clock support registered [ 0.596043] EDAC MC: Ver: 3.0.0 [ 0.597360] PCI: Using ACPI for IRQ routing [ 0.600560] NetLabel: Initializing [ 0.602016] NetLabel: domain hash size = 128 [ 0.604013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.606087] NetLabel: unlabeled traffic allowed by default [ 0.608145] vgaarb: loaded [ 0.610232] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.612016] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.617416] clocksource: Switched to clocksource kvm-clock [ 0.735551] VFS: Disk quotas dquot_6.6.0 [ 0.737749] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.740026] *** VALIDATE ramfs *** [ 0.741177] *** VALIDATE hugetlbfs *** [ 0.742750] pnp: PnP ACPI init [ 0.745177] pnp: PnP ACPI: found 6 devices [ 0.781565] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.784668] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.786788] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.788542] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.790725] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.792915] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.795624] NET: Registered protocol family 2 [ 0.797883] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.802936] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.805953] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.810886] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.814638] TCP: Hash tables configured (established 65536 bind 65536) [ 0.817626] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.820858] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.823879] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.827223] NET: Registered protocol family 1 [ 0.829867] RPC: Registered named UNIX socket transport module. [ 0.831792] RPC: Registered udp transport module. [ 0.833286] RPC: Registered tcp transport module. [ 0.834788] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.837096] NET: Registered protocol family 44 [ 0.838825] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.841216] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.843708] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.846316] PCI: CLS 0 bytes, default 64 [ 0.849120] Unpacking initramfs... [ 2.292767] debug: unmapping init [mem 0xffff8c947cc54000-0xffff8c947ffbffff] [ 2.296875] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.299257] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.302429] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.814101] Initialise system trusted keyrings [ 2.815771] Key type blacklist registered [ 2.817742] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.827774] zbud: loaded [ 2.831276] *** VALIDATE nfs *** [ 2.832607] *** VALIDATE nfs4 *** [ 2.834431] pstore: using deflate compression [ 2.838370] Platform Keyring initialized [ 2.950554] NET: Registered protocol family 38 [ 2.952646] Key type asymmetric registered [ 2.954263] Asymmetric key parser 'x509' registered [ 2.956214] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.959265] io scheduler mq-deadline registered [ 2.960818] io scheduler kyber registered [ 2.962562] io scheduler bfq registered [ 2.964266] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.967453] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.970557] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.972987] ACPI: Power Button [PWRF] [ 2.979198] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.986044] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.996308] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.002381] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.027174] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.056975] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.089023] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.093994] Non-volatile memory driver v1.3 [ 3.095532] Linux agpgart interface v0.103 [ 3.128760] virtio_blk virtio1: [vda] 133944 512-byte logical blocks (68.6 MB/65.4 MiB) [ 3.131723] vda: detected capacity change from 0 to 68579328 [ 3.146714] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.149566] vdb: detected capacity change from 0 to 1073741824 [ 3.163699] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.166211] vdc: detected capacity change from 0 to 2621440000 [ 3.180382] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.182748] vdd: detected capacity change from 0 to 2621440000 [ 3.199991] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.202845] vde: detected capacity change from 0 to 4294967296 [ 3.218202] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.221173] vdf: detected capacity change from 0 to 4294967296 [ 3.227704] libphy: Fixed MDIO Bus: probed [ 3.235063] usbcore: registered new interface driver usbserial_generic [ 3.238245] usbserial: USB Serial support registered for generic [ 3.240761] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.245188] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.247148] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.249842] mousedev: PS/2 mouse device common for all mice [ 3.251977] rtc_cmos 00:05: RTC can wake from S4 [ 3.254558] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.255274] rtc_cmos 00:05: registered as rtc0 [ 3.259646] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.262560] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.262881] intel_pstate: CPU model not supported [ 3.266974] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.272447] hid: raw HID events driver (C) Jiri Kosina [ 3.274234] usbcore: registered new interface driver usbhid [ 3.275799] usbhid: USB HID core driver [ 3.277471] drop_monitor: Initializing network drop monitor service [ 3.279526] Initializing XFRM netlink socket [ 3.281272] NET: Registered protocol family 10 [ 3.284134] Segment Routing with IPv6 [ 3.285110] NET: Registered protocol family 17 [ 3.287089] mpls_gso: MPLS GSO support [ 3.293860] RAS: Correctable Errors collector initialized. [ 3.295885] AVX version of gcm_enc/dec engaged. [ 3.297285] AES CTR mode by8 optimization enabled [ 3.376451] sched_clock: Marking stable (3376417654, 0)->(4259948926, -883531272) [ 3.379535] registered taskstats version 1 [ 3.381482] Loading compiled-in X.509 certificates [ 3.383774] zswap: loaded using pool lzo/zbud [ 3.410249] Key type big_key registered [ 3.426156] Key type encrypted registered [ 3.427480] ima: No TPM chip found, activating TPM-bypass! [ 3.429431] ima: Allocated hash algorithm: sha1 [ 3.430990] ima: No architecture policies found [ 3.432469] evm: Initialising EVM extended attributes: [ 3.434225] evm: security.selinux [ 3.435346] evm: security.ima [ 3.436282] evm: security.capability [ 3.437335] evm: HMAC attrs: 0x1 [ 3.439650] rtc_cmos 00:05: setting system clock to 2026-04-03 05:17:08 UTC (1775193428) [ 3.445274] debug: unmapping init [mem 0xffffffffb2e03000-0xffffffffb2ffffff] [ 3.448112] debug: unmapping init [mem 0xffffffffb1b82000-0xffffffffb1e58fff] [ 3.456133] Write protecting the kernel read-only data: 28672k [ 3.459278] debug: unmapping init [mem 0xffffffffb0203000-0xffffffffb03fffff] [ 3.461837] debug: unmapping init [mem 0xffffffffb0b14000-0xffffffffb0bfffff] [ 3.497155] 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.504334] systemd[1]: Detected virtualization kvm. [ 3.506380] systemd[1]: Detected architecture x86-64. [ 3.508025] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.535346] systemd[1]: No hostname configured. [ 3.537170] systemd[1]: Set hostname to . [ 3.539297] random: systemd: uninitialized urandom read (16 bytes read) [ 3.541754] systemd[1]: Initializing machine ID from random generator. [ 3.697725] random: systemd: uninitialized urandom read (16 bytes read) [ 3.699886] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.703322] random: systemd: uninitialized urandom read (16 bytes read) [ 3.705692] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 3.711692] systemd[1]: Reached target Paths. [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Reached target Local Encrypted Volumes. Starting Setup Virtual Console... [ OK ] Reached target Slices. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.418163] device-mapper: uevent: version 1.0.3 [ 4.421295] 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...[ 5.045641] random: fast init done [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.216503] virtio_net virtio0 ens2: renamed from eth0 [ 5.239210] scsi host0: ata_piix [ 5.267946] scsi host1: ata_piix [ 5.277984] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.280733] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.926164] dracut-initqueue[589]: RTNETLINK answers: File exists [ 9.942169] random: crng init done [ 9.943740] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.533576] 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. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ 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 Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.771776] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.025634] SELinux: Disabled at runtime. [ 12.083837] 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) [ 12.090936] systemd[1]: Detected virtualization kvm. [ 12.092827] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.575817] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.578371] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.582169] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.585924] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.588926] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.596587] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.612436] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Created slice system-getty.slice. [ OK ] Listening on udev Control Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Create list of required st…ce nodes for the current kernel... Mounting POSIX Message Queue File System... [ OK ] Created slice User and Session Slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Starting Remount Root and Kernel File Systems... Starting Apply Kernel Variables... Mounting Huge Pages File System... Mounting Kernel Debug File System... [ OK ] Reached target Slices. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ 12.757268] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted POSIX Message Queue File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ OK ] Started udev[ 13.057782] squashfs: version 4.0 (2009/01/31) Phillip Lougher Coldplug all Devices. [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.451365] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.521823] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.596828] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.609868] EDAC sbridge: Ver: 1.1.2 [ 15.248096] Key type dns_resolver registered [ 15.548670] NFS: Registering the id_resolver key type [ 15.550649] Key type id_resolver registered [ 15.552029] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. [ OK ] Reached target sshd-keygen.target. Starting Network Manager... [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ 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 System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg208-server login: [ 34.537296] spl: loading out-of-tree module taints kernel. [ 37.358598] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 46.447992] Key type ._llcrypt registered [ 46.457660] Key type .llcrypt registered [ 46.555755] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 76.456854] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 77.870701] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 77.887977] alg: No test for adler32 (adler32-zlib) [ 79.163408] Lustre: Lustre: Build Version: 2.17.51_74_g48b5ed2 [ 80.160027] hrtimer: interrupt took 12015719 ns [ 80.647211] LNet: Added LNI 192.168.202.108@tcp [8/256/0/180] [ 82.585419] Key type lgssc registered [ 85.439199] Lustre: Echo OBD driver; http://www.lustre.org/ [ 98.093390] vdc: vdc1 vdc9 [ 110.144389] vde: vde1 vde9 [ 122.866902] vdf: vdf1 vdf9 [ 146.166757] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 157.459904] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 158.929512] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 159.357355] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 159.466090] Lustre: lustre-MDT0000: new disk, initializing [ 159.977133] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 160.039339] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 165.761451] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 171.301898] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 178.247551] Lustre: lustre-OST0000: new disk, initializing [ 178.253733] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 178.264103] Lustre: Skipped 1 previous similar message [ 178.352383] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 185.075682] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 185.086848] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 185.238450] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 186.242962] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 199.144290] Lustre: lustre-OST0001: new disk, initializing [ 199.148307] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 199.285351] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 207.796927] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 210.018950] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 210.022558] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 210.163833] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 222.225203] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 232.453413] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 245.929212] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing check_logdir /tmp/testlogs/ [ 252.580860] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing yml_node [ 256.912389] Lustre: DEBUG MARKER: Client: 2.17.51.74 [ 259.833481] Lustre: DEBUG MARKER: MDS: 2.17.51.74 [ 262.760553] Lustre: DEBUG MARKER: OSS: 2.17.51.74 [ 265.036777] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Fri Apr 3 01:21:28 EDT 2026 [ 287.589748] Lustre: DEBUG MARKER: excepting tests: 59 36 [ 289.966288] Lustre: DEBUG MARKER: === replay-single: start setup 01:21:53 (1775193713) === [ 294.962881] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing check_config_client /mnt/lustre [ 315.484269] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 319.926006] Lustre: 11022:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 325.964899] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 331.127620] Lustre: DEBUG MARKER: === replay-single: finish setup 01:22:34 (1775193754) === [ 333.786382] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 01:22:37 (1775193757) [ 337.507979] LustreError: 11502:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 338.713672] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 341.188419] Lustre: Failing over lustre-MDT0000 [ 341.557782] Lustre: server umount lustre-MDT0000 complete [ 358.885317] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193767/real 1775193767] req@ffff8c94faa14000 x1861425304760832/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193783 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 358.886241] 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 [ 358.931475] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 358.946515] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 363.042731] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193772/real 1775193772] req@ffff8c94fc7a8380 x1861425304761088/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193788 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 368.099552] Lustre: 3325:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193777/real 1775193777] req@ffff8c94f626dc00 x1861425304761472/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193793 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 368.177326] Lustre: 3325:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 369.121678] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94fae76300 x1861425304762752/t0(0) o250->MGC192.168.202.108@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 [ 369.996899] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 370.720846] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 370.862887] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 373.280229] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193782/real 1775193782] req@ffff8c94faa17b80 x1861425304761984/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193798 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 376.295130] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 384.484657] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 386.676636] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 388.772138] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 399.393073] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 01:23:42 (1775193822) [ 402.426484] Lustre: Failing over lustre-OST0000 [ 402.544180] Lustre: server umount lustre-OST0000 complete [ 404.963399] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 404.973878] Lustre: Skipped 1 previous similar message [ 410.082064] LustreError: 10097:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 410.116218] LustreError: 10097:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 412.073362] LustreError: 6575:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 415.201922] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 420.326431] LustreError: 6575:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 420.344710] LustreError: 6575:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 423.141972] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 424.580899] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 425.178089] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 425.178114] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 425.196749] Lustre: Skipped 1 previous similar message [ 432.286095] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 442.966848] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 445.130171] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 457.601678] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 01:24:41 (1775193881) [ 461.550259] LustreError: 14239:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 462.592438] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 465.128535] Lustre: Failing over lustre-MDT0000 [ 465.717707] Lustre: server umount lustre-MDT0000 complete [ 485.349699] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 485.575924] 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 [ 485.592599] Lustre: Skipped 1 previous similar message [ 485.820899] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 486.816135] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193894/real 1775193894] req@ffff8c94fbf50380 x1861425304796032/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193910 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 486.861540] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 490.999439] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 491.912144] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 495.073027] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775193904/real 1775193904] req@ffff8c94db43dc00 x1861425304796800/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775193920 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 495.118400] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 495.455370] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 495.465240] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 500.647253] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:54 [ 500.668256] Lustre: Skipped 1 previous similar message [ 505.760480] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:49 [ 510.882501] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:44 [ 516.004148] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:39 [ 526.253028] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:29 [ 526.278403] Lustre: Skipped 1 previous similar message [ 546.725182] Lustre: lustre-MDT0000: Denying connection for new client 3a54c8ab-6798-481c-8cf3-193de4477846 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:08 [ 546.761477] Lustre: Skipped 3 previous similar messages [ 555.500366] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 555.506920] Lustre: 14831:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 69c354c3-2ce9-45f9-a763-80dae52813a1@ [ 555.518668] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 555.625538] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 555.668773] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:65) [ 555.673544] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:65) [ 568.257585] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 01:26:31 (1775193991) [ 572.163231] LustreError: 15550:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 573.017400] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 575.859700] Lustre: Failing over lustre-MDT0000 [ 576.314473] Lustre: server umount lustre-MDT0000 complete [ 594.400572] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775194003/real 1775194003] req@ffff8c94db43ce00 x1861425304820480/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775194019 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 594.403624] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 594.451743] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 594.495821] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 604.877836] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 604.964996] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 609.833680] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 612.486554] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 612.495743] Lustre: lustre-MDT0000: Denying connection for new client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 612.515157] Lustre: Skipped 1 previous similar message [ 619.501235] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 619.527332] Lustre: Skipped 1 previous similar message [ 672.500272] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 672.507687] Lustre: 16154:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 3a54c8ab-6798-481c-8cf3-193de4477846@ [ 672.523796] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 672.623525] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 672.681159] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:97) [ 672.694543] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:97) [ 687.611673] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 01:28:31 (1775194111) [ 691.720468] LustreError: 16872:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 692.828728] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 695.054870] Lustre: Failing over lustre-MDT0000 [ 695.238359] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.8@tcp (stopping) [ 695.366659] Lustre: server umount lustre-MDT0000 complete [ 712.544233] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775194121/real 1775194121] req@ffff8c94e4664a80 x1861425304844800/t0(0) o400->MGC192.168.202.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1775194137 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 712.577389] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 712.595795] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 712.659364] 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 [ 712.680364] Lustre: Skipped 1 previous similar message [ 723.683636] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 723.789321] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 729.715594] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 735.142114] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 735.292814] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 735.318506] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:129) [ 735.318774] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:129) [ 737.845124] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 737.859846] Lustre: Skipped 1 previous similar message [ 739.885168] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 741.644876] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 751.266515] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 01:29:35 (1775194175) [ 754.580589] LustreError: 18316:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 755.496413] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 757.784464] Lustre: Failing over lustre-MDT0000 [ 758.255955] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 758.283020] Lustre: Skipped 1 previous similar message [ 758.294709] LustreError: 17441:0:(ldlm_lib.c:1179: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. [ 758.318267] LustreError: 17441:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 758.483508] Lustre: server umount lustre-MDT0000 complete [ 774.499145] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 785.935357] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 787.382508] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 787.848229] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 787.930677] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:131 to 0x240000400:161) [ 787.931409] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:161) [ 792.298633] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 798.185674] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 798.213034] Lustre: Skipped 1 previous similar message [ 802.616385] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 804.407921] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 814.883260] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 01:30:38 (1775194238) [ 819.044897] LustreError: 19749:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 820.280786] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 822.412798] Lustre: Failing over lustre-MDT0000 [ 822.712874] Lustre: server umount lustre-MDT0000 complete [ 839.142741] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775194248/real 1775194248] req@ffff8c94fbf50a80 x1861425304877568/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775194264 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 839.145462] 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 [ 839.174223] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 839.175815] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 839.213435] Lustre: Skipped 2 previous similar messages [ 850.006127] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 850.011287] Lustre: Skipped 1 previous similar message [ 850.076083] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 854.905436] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 864.163367] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 864.246461] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 864.258625] Lustre: Skipped 1 previous similar message [ 864.368784] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 864.415414] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:193) [ 864.422716] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:163 to 0x240000400:193) [ 868.744586] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 870.863707] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 881.602357] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 01:31:45 (1775194305) [ 885.741491] LustreError: 21184:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 887.059060] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 889.687291] Lustre: Failing over lustre-MDT0000 [ 889.827527] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 889.842245] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 890.024508] Lustre: server umount lustre-MDT0000 complete [ 909.559422] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 910.084233] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 910.255825] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 910.521867] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 910.575873] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:225) [ 910.579674] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:225) [ 910.946324] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 910.956213] Lustre: Skipped 1 previous similar message [ 914.826156] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 923.802687] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 925.956917] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 936.594571] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 01:32:40 (1775194360) [ 940.531807] LustreError: 22622:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 941.749000] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 944.149914] Lustre: Failing over lustre-MDT0000 [ 944.510511] Lustre: server umount lustre-MDT0000 complete [ 962.608647] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 963.059927] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 963.074488] Lustre: Skipped 1 previous similar message [ 963.245508] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 963.611486] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:257) [ 963.615363] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:257) [ 968.517086] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 969.185529] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775194377/real 1775194377] req@ffff8c94fc887480 x1861425304911104/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775194393 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 969.234534] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 978.077617] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 979.990372] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 990.388589] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 01:33:33 (1775194413) [ 991.877739] Lustre: *** cfs_fail_loc=13b, val=315*** [ 991.883948] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 991.889564] LustreError: 23170:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94db6c9180 x1861425275463808/t38654705666(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:683/0 lens 392/456 e 0 to 0 dl 1775194433 ref 1 fl Interpret:/600/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 997.042287] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 998.911079] Lustre: Failing over lustre-MDT0000 [ 999.202101] Lustre: server umount lustre-MDT0000 complete [ 1018.772973] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1018.776715] Lustre: Skipped 2 previous similar messages [ 1018.841493] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1023.471895] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1023.522717] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1023.536964] Lustre: Skipped 1 previous similar message [ 1023.652500] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1023.662697] Lustre: Skipped 1 previous similar message [ 1023.716216] Lustre: 24639:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fbaa5c00 x1861425275463808/t38654705666(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:715/0 lens 392/456 e 0 to 0 dl 1775194465 ref 1 fl Interpret:/602/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 1023.719937] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:289) [ 1023.720217] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:289) [ 1023.971071] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1023.983649] Lustre: Skipped 3 previous similar messages [ 1031.918228] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1034.127663] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1044.694699] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 01:34:28 (1775194468) [ 1048.606579] LustreError: 25503:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1048.613530] LustreError: 25503:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 1049.671722] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1052.302715] Lustre: Failing over lustre-MDT0000 [ 1052.762820] Lustre: server umount lustre-MDT0000 complete [ 1070.051085] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1070.070778] LustreError: Skipped 1 previous similar message [ 1081.236548] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1081.660550] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:321) [ 1081.676231] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:321) [ 1085.737305] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1097.144328] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1099.936409] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1112.296511] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 01:35:35 (1775194535) [ 1118.080285] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1119.241737] Lustre: *** cfs_fail_loc=114, val=0*** [ 1122.697715] Lustre: Failing over lustre-MDT0000 [ 1123.225556] Lustre: server umount lustre-MDT0000 complete [ 1142.567760] LustreError: 27589:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1142.594307] LustreError: 27589:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 1142.740168] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1142.753908] Lustre: Skipped 6 previous similar messages [ 1142.764503] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 1142.775422] Lustre: Skipped 1 previous similar message [ 1144.458762] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:353) [ 1144.459809] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:353) [ 1147.527249] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1156.977681] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1159.424125] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1169.155918] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 01:36:32 (1775194592) [ 1174.123789] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1175.122323] Lustre: *** cfs_fail_loc=128, val=0*** [ 1178.845810] Lustre: Failing over lustre-MDT0000 [ 1179.204843] Lustre: server umount lustre-MDT0000 complete [ 1199.199388] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1199.224719] LustreError: Skipped 1 previous similar message [ 1199.955694] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1199.967399] Lustre: Skipped 1 previous similar message [ 1200.074550] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1200.086784] Lustre: Skipped 2 previous similar messages [ 1200.244345] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1200.251572] Lustre: Skipped 2 previous similar messages [ 1200.299680] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:385) [ 1200.305208] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:385) [ 1204.656964] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1209.341962] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1209.350352] Lustre: Skipped 5 previous similar messages [ 1213.364455] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1215.470587] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1224.987432] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 01:37:28 (1775194648) [ 1228.531268] LustreError: 29978:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1228.537933] LustreError: 29978:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 1229.596179] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1232.100931] Lustre: Failing over lustre-MDT0000 [ 1232.490179] Lustre: server umount lustre-MDT0000 complete [ 1250.081257] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775194659/real 1775194659] req@ffff8c94e4664000 x1861425304993152/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775194675 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1250.129693] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 36 previous similar messages [ 1262.938400] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:391 to 0x280000400:417) [ 1262.958742] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:391 to 0x240000400:417) [ 1266.345569] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1275.137251] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1277.746810] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1291.717622] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 01:38:34 (1775194714) [ 1298.216497] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1301.658183] Lustre: Failing over lustre-MDT0000 [ 1302.060351] Lustre: server umount lustre-MDT0000 complete [ 1322.543276] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1322.547158] Lustre: Skipped 4 previous similar messages [ 1327.983813] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1336.556317] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:423 to 0x280000400:449) [ 1336.556525] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:423 to 0x240000400:449) [ 1341.196480] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1343.572841] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1354.453553] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 01:39:37 (1775194777) [ 1359.088157] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1369.891627] Lustre: Failing over lustre-MDT0000 [ 1370.259968] Lustre: server umount lustre-MDT0000 complete [ 1389.803193] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1389.817033] Lustre: Skipped 2 previous similar messages [ 1394.364884] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1401.598021] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:577) [ 1401.598368] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:577) [ 1406.040936] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1408.360653] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1435.310143] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 01:40:59 (1775194859) [ 1439.561604] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1441.897554] Lustre: Failing over lustre-MDT0000 [ 1442.304605] Lustre: server umount lustre-MDT0000 complete [ 1459.699433] 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 [ 1459.717958] Lustre: Skipped 9 previous similar messages [ 1459.718686] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1459.756845] LustreError: Skipped 3 previous similar messages [ 1468.963494] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94c892aa00 x1861425305111808/t0(0) o250->MGC192.168.202.108@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 [ 1470.374951] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1470.389638] Lustre: Skipped 3 previous similar messages [ 1470.744796] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1470.762946] Lustre: Skipped 3 previous similar messages [ 1470.840467] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:609) [ 1470.840744] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:609) [ 1476.746845] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1484.000967] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1484.011527] Lustre: Skipped 7 previous similar messages [ 1486.902081] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1489.485166] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1500.795556] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 01:42:04 (1775194924) [ 1504.130616] LustreError: 35760:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1504.137148] LustreError: 35760:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 1505.180956] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1507.696624] Lustre: Failing over lustre-MDT0000 [ 1508.024587] Lustre: server umount lustre-MDT0000 complete [ 1535.204604] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94f59d7b80 x1861425305128960/t0(0) o250->MGC192.168.202.108@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 [ 1537.318404] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:641) [ 1537.321404] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:641) [ 1541.816719] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1551.547853] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1553.894429] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1564.662375] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 01:43:08 (1775194988) [ 1569.411457] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1571.898482] Lustre: Failing over lustre-MDT0000 [ 1572.403184] Lustre: server umount lustre-MDT0000 complete [ 1598.113173] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94f59d4380 x1861425305146112/t0(0) o250->MGC192.168.202.108@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 [ 1599.648208] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:673) [ 1599.653898] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:673) [ 1604.825808] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1614.965628] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1617.256916] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1628.388266] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 01:44:11 (1775195051) [ 1633.483960] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1636.283644] Lustre: Failing over lustre-MDT0000 [ 1636.665830] Lustre: server umount lustre-MDT0000 complete [ 1665.145611] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1665.176031] Lustre: Skipped 3 previous similar messages [ 1666.258416] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:705) [ 1666.262326] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:705) [ 1670.426245] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1679.319781] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1681.877300] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1692.471705] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 01:45:16 (1775195116) [ 1698.526848] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1701.476793] Lustre: Failing over lustre-MDT0000 [ 1701.816202] LustreError: 39160:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1701.910221] Lustre: server umount lustre-MDT0000 complete [ 1730.007426] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1742.009315] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:737) [ 1742.015146] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:737) [ 1748.152894] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1750.308765] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1762.085893] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 01:46:25 (1775195185) [ 1766.755765] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1768.950548] Lustre: Failing over lustre-MDT0000 [ 1769.223126] Lustre: server umount lustre-MDT0000 complete [ 1789.927233] Lustre: 3325:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775195198/real 1775195198] req@ffff8c94faa51f80 x1861425305197696/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775195214 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1789.972525] Lustre: 3325:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 60 previous similar messages [ 1795.581330] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1798.194705] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:769) [ 1798.207280] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:769) [ 1804.876624] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1807.607828] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1819.144855] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 01:47:22 (1775195242) [ 1824.342216] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1827.072652] Lustre: Failing over lustre-MDT0000 [ 1827.530470] Lustre: server umount lustre-MDT0000 complete [ 1855.457240] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94cdd3c000 x1861425305215616/t0(0) o250->MGC192.168.202.108@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 [ 1856.148801] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1856.159914] Lustre: Skipped 7 previous similar messages [ 1861.885596] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1870.231851] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:801) [ 1870.238297] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:801) [ 1875.440255] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1877.884752] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1888.356510] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 01:48:32 (1775195312) [ 1893.878603] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1896.356714] Lustre: Failing over lustre-MDT0000 [ 1896.851642] Lustre: server umount lustre-MDT0000 complete [ 1922.711269] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1926.446110] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:833) [ 1926.457282] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:833) [ 1932.471594] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1934.797226] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1948.173370] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 01:49:31 (1775195371) [ 1953.920702] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1956.302812] Lustre: Failing over lustre-MDT0000 [ 1956.760361] Lustre: server umount lustre-MDT0000 complete [ 1974.497508] 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 [ 1974.512516] Lustre: Skipped 14 previous similar messages [ 1975.522441] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1975.533433] LustreError: Skipped 7 previous similar messages [ 1991.576523] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1997.756643] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1997.768676] Lustre: Skipped 7 previous similar messages [ 1997.950923] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1997.966341] Lustre: Skipped 7 previous similar messages [ 1998.033792] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:865) [ 1998.036524] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:835 to 0x240000400:865) [ 1999.468648] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1999.476062] Lustre: Skipped 15 previous similar messages [ 2003.465976] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2005.753264] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2019.051868] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 01:50:42 (1775195442) [ 2023.454093] LustreError: 47203:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2023.461111] LustreError: 47203:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 2024.370382] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2026.844417] Lustre: Failing over lustre-MDT0000 [ 2027.172430] Lustre: server umount lustre-MDT0000 complete [ 2046.945866] LustreError: 47771:0:(ldlm_lib.c:1179: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. [ 2046.962439] LustreError: 47771:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 2052.841386] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2054.322251] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:897) [ 2054.327202] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:867 to 0x240000400:897) [ 2063.999574] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2066.744377] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2078.341475] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 01:51:41 (1775195501) [ 2082.903273] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2085.153946] Lustre: Failing over lustre-MDT0000 [ 2085.615736] Lustre: server umount lustre-MDT0000 complete [ 2114.016932] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94f626fb80 x1861425305287680/t0(0) o250->MGC192.168.202.108@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 [ 2115.907404] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:929) [ 2115.913053] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:929) [ 2120.688443] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2131.837446] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2133.630236] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2145.258389] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 01:52:48 (1775195568) [ 2150.615349] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2153.511231] Lustre: Failing over lustre-MDT0000 [ 2154.106914] Lustre: server umount lustre-MDT0000 complete [ 2183.506285] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2183.520769] Lustre: Skipped 7 previous similar messages [ 2190.071824] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2197.849559] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:961) [ 2197.853830] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:931 to 0x240000400:961) [ 2203.747724] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2206.573692] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2219.115882] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 01:54:02 (1775195642) [ 2224.195584] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2227.232777] Lustre: Failing over lustre-MDT0000 [ 2227.638339] Lustre: server umount lustre-MDT0000 complete [ 2253.247211] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2254.013948] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:963 to 0x240000400:993) [ 2254.015342] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:993) [ 2263.866176] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2267.674426] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2279.268930] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 01:55:03 (1775195703) [ 2285.062474] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2287.766959] Lustre: Failing over lustre-MDT0000 [ 2288.082610] Lustre: server umount lustre-MDT0000 complete [ 2316.496039] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:995 to 0x280000400:1025) [ 2316.502020] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:995 to 0x240000400:1025) [ 2320.210622] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2330.536091] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2333.617481] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2346.282036] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 01:56:09 (1775195769) [ 2350.562959] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2353.451914] Lustre: Failing over lustre-MDT0000 [ 2353.859363] Lustre: server umount lustre-MDT0000 complete [ 2381.283339] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94d0d1c700 x1861425305359872/t0(0) o250->MGC192.168.202.108@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 [ 2383.045027] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1057) [ 2383.049219] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1057) [ 2387.276859] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2396.803750] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2399.188651] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2410.373371] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 01:57:13 (1775195833) [ 2416.253822] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2419.180732] Lustre: Failing over lustre-MDT0000 [ 2420.036324] Lustre: server umount lustre-MDT0000 complete [ 2438.624483] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775195847/real 1775195847] req@ffff8c94fbaa6680 x1861425305375232/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775195863 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2438.681768] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 81 previous similar messages [ 2448.865685] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94fbf52a00 x1861425305377024/t0(0) o250->MGC192.168.202.108@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 [ 2450.657156] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1089) [ 2450.667733] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1059 to 0x240000400:1089) [ 2454.931502] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2464.984699] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2467.474651] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2478.828933] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 01:58:22 (1775195902) [ 2484.991903] Lustre: 57287:0:(genops.c:1793:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 at adminstrative request [ 2490.661260] Lustre: Failing over lustre-MDT0000 [ 2491.105662] Lustre: server umount lustre-MDT0000 complete [ 2511.244924] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2511.249536] Lustre: Skipped 9 previous similar messages [ 2517.032735] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1091 to 0x240000400:1121) [ 2517.035079] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1121) [ 2517.191852] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2527.014342] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2528.971700] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2535.137089] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2551.244932] Lustre: DEBUG MARKER: before 4096, after 4096 [ 2559.777796] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 01:59:43 (1775195983) [ 2561.171785] Lustre: 59081:0:(genops.c:1793:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 at adminstrative request [ 2571.519774] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 01:59:55 (1775195995) [ 2576.128961] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2578.189828] Lustre: Failing over lustre-MDT0000 [ 2578.346825] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.8@tcp (stopping) [ 2578.528722] Lustre: server umount lustre-MDT0000 complete [ 2596.963401] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2596.979940] LustreError: Skipped 8 previous similar messages [ 2597.354567] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2597.362520] Lustre: Skipped 17 previous similar messages [ 2597.797223] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2597.806870] Lustre: Skipped 8 previous similar messages [ 2598.052633] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2598.056923] Lustre: Skipped 8 previous similar messages [ 2598.080537] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1124 to 0x240000400:1153) [ 2598.080600] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1123 to 0x280000400:1153) [ 2602.218340] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2603.004738] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2603.010072] Lustre: Skipped 17 previous similar messages [ 2611.577791] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2613.994643] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2624.935079] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 02:00:48 (1775196048) [ 2628.632480] LustreError: 60852:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2628.638268] LustreError: 60852:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 2629.581339] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2631.913498] Lustre: Failing over lustre-MDT0000 [ 2632.225344] Lustre: server umount lustre-MDT0000 complete [ 2659.302960] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94fc90d180 x1861425305434880/t0(0) o250->MGC192.168.202.108@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 [ 2662.472929] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1155 to 0x240000400:1185) [ 2662.475815] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1155 to 0x280000400:1185) [ 2665.678493] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2675.808435] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2677.937238] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2689.594142] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 02:01:53 (1775196113) [ 2694.516741] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2696.758381] Lustre: Failing over lustre-MDT0000 [ 2697.033735] Lustre: server umount lustre-MDT0000 complete [ 2715.621103] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 2716.832810] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1187 to 0x240000400:1217) [ 2716.836140] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1187 to 0x280000400:1217) [ 2721.672668] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2731.097278] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2732.989994] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2743.829283] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 02:02:47 (1775196167) [ 2748.557694] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2750.409676] Lustre: Failing over lustre-MDT0000 [ 2750.784530] Lustre: server umount lustre-MDT0000 complete [ 2777.068841] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a29474c [ 2779.638318] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1219 to 0x240000400:1249) [ 2779.645658] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1249) [ 2784.011222] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2793.165043] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2795.391716] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2806.857297] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 02:03:50 (1775196230) [ 2811.862470] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2814.231310] Lustre: Failing over lustre-MDT0000 [ 2814.491046] Lustre: server umount lustre-MDT0000 complete [ 2833.377583] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 2833.380782] Lustre: Skipped 2 previous similar messages [ 2833.560084] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2833.570358] Lustre: Skipped 9 previous similar messages [ 2834.523510] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1251 to 0x240000400:1281) [ 2834.524478] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1281) [ 2838.942635] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2848.216809] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2850.465320] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2860.250432] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 02:04:44 (1775196284) [ 2864.542672] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2867.279611] Lustre: Failing over lustre-MDT0000 [ 2867.744855] Lustre: server umount lustre-MDT0000 complete [ 2886.390425] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.8@tcp (not set up) [ 2888.272977] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1283 to 0x280000400:1313) [ 2888.273558] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1283 to 0x240000400:1313) [ 2892.035731] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2900.376121] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2902.140976] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2912.260356] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 02:05:35 (1775196335) [ 2916.789785] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2919.437718] Lustre: Failing over lustre-MDT0000 [ 2919.908502] Lustre: server umount lustre-MDT0000 complete [ 2938.862523] Lustre: MGS: Not available for connect from 0@lo (not set up) [ 2945.002216] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2948.373497] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1315 to 0x280000400:1345) [ 2948.375991] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1315 to 0x240000400:1345) [ 2953.861360] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2955.748564] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2965.478823] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 02:06:29 (1775196389) [ 2970.784764] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2973.153113] Lustre: Failing over lustre-MDT0000 [ 2973.476593] Lustre: server umount lustre-MDT0000 complete [ 3006.952956] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3014.858667] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1347 to 0x240000400:1377) [ 3014.860426] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1347 to 0x280000400:1377) [ 3019.825666] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3021.920685] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3031.113838] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 02:07:34 (1775196454) [ 3035.427405] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3037.484333] Lustre: Failing over lustre-MDT0000 [ 3037.774646] Lustre: server umount lustre-MDT0000 complete [ 3055.763132] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1379 to 0x280000400:1409) [ 3055.765063] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1379 to 0x240000400:1409) [ 3057.120112] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775196466/real 1775196466] req@ffff8c94c46e4000 x1861425305549440/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775196482 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3057.171685] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 76 previous similar messages [ 3060.414145] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3068.160887] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3069.269839] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3081.693555] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 02:08:24 (1775196504) [ 3090.656658] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3094.278388] Lustre: Failing over lustre-MDT0000 [ 3094.544956] Lustre: server umount lustre-MDT0000 complete [ 3123.264163] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3123.269689] Lustre: Skipped 9 previous similar messages [ 3124.825453] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1411 to 0x280000400:1441) [ 3124.826392] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1411 to 0x240000400:1441) [ 3129.944667] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3140.862135] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3143.277493] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3154.233949] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 02:09:38 (1775196578) [ 3158.745827] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3160.869813] Lustre: Failing over lustre-MDT0000 [ 3161.266707] Lustre: server umount lustre-MDT0000 complete [ 3178.486423] LustreError: 74252:0:(ldlm_lib.c:1179: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. [ 3178.511214] LustreError: 74252:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3179.664591] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1443 to 0x280000400:1473) [ 3179.665168] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1443 to 0x240000400:1473) [ 3183.946736] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3191.618542] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3193.460925] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3201.456827] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 02:10:25 (1775196625) [ 3202.477578] Lustre: 75029:0:(genops.c:1793:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 at adminstrative request [ 3213.556632] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 02:10:37 (1775196637) [ 3216.622958] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3218.712906] Lustre: Failing over lustre-MDT0000 [ 3219.103908] Lustre: server umount lustre-MDT0000 complete [ 3228.174480] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3228.186050] LustreError: Skipped 10 previous similar messages [ 3228.432660] 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 [ 3228.443186] Lustre: Skipped 22 previous similar messages [ 3228.686976] Lustre: lustre-MDT0000: Aborting client recovery [ 3228.690396] LustreError: 75891:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3228.695908] Lustre: 75941:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3228.701565] Lustre: 75941:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 3228.713263] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3228.759309] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 3228.863184] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1480 to 0x240000400:1505) [ 3228.866620] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1479 to 0x280000400:1505) [ 3233.032433] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3233.762286] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3233.773748] Lustre: Skipped 22 previous similar messages [ 3247.176188] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 02:11:11 (1775196671) [ 3250.609280] LustreError: 76632:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3250.615262] LustreError: 76632:0:(osd_handler.c:720:osd_ro()) Skipped 10 previous similar messages [ 3251.639757] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3253.441676] Lustre: Failing over lustre-MDT0000 [ 3253.750178] Lustre: server umount lustre-MDT0000 complete [ 3263.139614] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3263.164467] Lustre: lustre-MDT0000: Aborting client recovery [ 3263.166488] LustreError: 77204:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3263.175146] Lustre: 77253:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3263.181380] Lustre: 77253:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 3263.187216] Lustre: 77253:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 3263.200886] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3263.240830] Lustre: lustre-MDT0000-osd: cancel update llog [0x200015bc0:0x1:0x0] [ 3263.345101] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1516 to 0x280000400:1537) [ 3263.349943] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1516 to 0x240000400:1537) [ 3268.300997] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3274.534755] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3283.201913] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 02:11:47 (1775196707) [ 3287.239412] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3289.368214] Lustre: Failing over lustre-MDT0000 [ 3289.712187] Lustre: server umount lustre-MDT0000 complete [ 3299.600947] Lustre: lustre-MDT0000: Aborting client recovery [ 3299.603857] LustreError: 78514:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3299.619579] Lustre: 78565:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3299.629100] Lustre: 78565:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 3299.636068] Lustre: 78565:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 3299.642977] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3299.676665] Lustre: lustre-MDT0000-osd: cancel update llog [0x200016778:0x1:0x0] [ 3299.790260] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1569) [ 3299.796851] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1544 to 0x280000400:1569) [ 3304.003743] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3319.215602] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 02:12:22 (1775196742) [ 3320.499751] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3320.507431] LustreError: 78918:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94fc0c6680 x1861425276471552/t201863462916(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:741/0 lens 512/456 e 0 to 0 dl 1775196756 ref 1 fl Interpret:/200/0 rc 0/0 job:'rm.0' uid:0 gid:0 projid:4294967295 [ 3324.551082] Lustre: Failing over lustre-MDT0000 [ 3324.827530] Lustre: server umount lustre-MDT0000 complete [ 3334.538403] Lustre: lustre-MDT0000: Aborting client recovery [ 3334.544560] LustreError: 79668:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3334.552382] Lustre: 79718:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3334.562566] Lustre: 79718:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 3334.570220] Lustre: 79718:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 3334.584275] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3334.683919] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017330:0x1:0x0] [ 3334.780775] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1601) [ 3334.789674] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1571 to 0x280000400:1601) [ 3339.147753] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3352.162569] Lustre: DEBUG MARKER: SKIP: replay-single test_36 skipping ALWAYS excluded test 36 [ 3354.168258] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 02:12:58 (1775196778) [ 3358.350571] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3361.402191] Lustre: Failing over lustre-MDT0000 [ 3361.693324] Lustre: server umount lustre-MDT0000 complete [ 3371.016859] Lustre: lustre-MDT0000: Aborting client recovery [ 3371.018546] LustreError: 81065:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3371.026467] Lustre: 81115:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3371.035543] Lustre: 81115:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 3371.049961] Lustre: 81115:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 3371.061116] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3371.109823] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017b00:0x1:0x0] [ 3371.179235] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1571 to 0x280000400:1633) [ 3371.179628] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1633) [ 3375.452634] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3389.053497] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 02:13:32 (1775196812) [ 3430.080779] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3432.311983] Lustre: Failing over lustre-MDT0000 [ 3432.423549] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3432.428803] Lustre: Skipped 1 previous similar message [ 3432.616947] Lustre: server umount lustre-MDT0000 complete [ 3454.228466] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3454.256020] Lustre: Skipped 21 previous similar messages [ 3460.028694] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3460.055930] Lustre: Skipped 10 previous similar messages [ 3460.320933] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3460.462651] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3460.475425] Lustre: Skipped 10 previous similar messages [ 3460.570465] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2034 to 0x280000400:2049) [ 3460.573130] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2034 to 0x240000400:2049) [ 3470.489947] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3472.169770] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3502.387056] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 02:15:26 (1775196926) [ 3530.940723] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3545.474120] Lustre: Failing over lustre-MDT0000 [ 3545.881533] Lustre: server umount lustre-MDT0000 complete [ 3575.776534] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c93cd57a300 x1861425305871104/t0(0) o250->MGC192.168.202.108@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 [ 3582.680340] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3593.365671] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2450 to 0x280000400:2465) [ 3593.376236] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2450 to 0x240000400:2465) [ 3597.848611] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3600.445890] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3628.939883] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 02:17:32 (1775197052) [ 3631.389482] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 3632.568965] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3632.573476] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3640.208707] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 02:17:44 (1775197064) [ 3669.184822] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 3682.903912] Lustre: Failing over lustre-OST0000 [ 3683.011471] Lustre: server umount lustre-OST0000 complete [ 3685.326655] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3685.426392] LustreError: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -107 [ 3685.437029] LustreError: Skipped 1 previous similar message [ 3706.841592] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3772.878598] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 02:19:56 (1775197196) [ 3778.145187] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3781.521437] Lustre: Failing over lustre-MDT0000 [ 3781.793192] Lustre: server umount lustre-MDT0000 complete [ 3797.984666] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775197207/real 1775197207] req@ffff8c93ccdb2680 x1861425306130048/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775197223 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3798.027471] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 48 previous similar messages [ 3808.238909] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a2db403 [ 3808.927391] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3808.936742] Lustre: Skipped 9 previous similar messages [ 3809.320153] Lustre: *** cfs_fail_loc=204, val=2147483648*** [ 3809.322260] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2881) [ 3815.266966] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3824.043671] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3825.650174] LustreError: 88700:0:(osp_precreate.c:969:osp_precreate_cleanup_orphans()) lustre-OST0000-osc-MDT0000: cannot cleanup orphans: rc = -11 [ 3825.667662] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3826.098179] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3826.723724] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2913) [ 3847.728246] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 02:21:11 (1775197271) [ 3854.414369] LustreError: 89116:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3859.936210] LustreError: 89116:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3859.954000] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3860.032315] LustreError: 6572:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 waking [ 3862.124097] LustreError: 88678:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3867.616135] LustreError: 88678:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3867.623575] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3869.878286] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3875.297569] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3875.301915] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3877.746876] LustreError: 89116:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3882.976153] LustreError: 89116:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3885.122404] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3890.144581] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3890.161937] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3890.182209] Lustre: Skipped 1 previous similar message [ 3899.737335] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3899.745537] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 1 previous similar message [ 3904.993892] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3905.005683] LustreError: 89883:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 1 previous similar message [ 3912.674664] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3912.694127] Lustre: Skipped 2 previous similar messages [ 3922.410840] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3922.413922] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 2 previous similar messages [ 3927.520174] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3927.528099] LustreError: 88676:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 2 previous similar messages [ 3938.869398] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 02:22:42 (1775197362) [ 3940.990158] LustreError: 88676:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3950.503455] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 3955.614189] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 3960.737205] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 3964.126097] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 3970.975233] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 3970.987939] Lustre: Skipped 1 previous similar message [ 3981.072439] LustreError: 88676:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3981.110393] Lustre: 88676:0:(service.c:2561:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff8c93c6f20e00 x1861425279116800/t0(0) o38->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1775197386 ref 1 fl Complete:H/200/0 rc 0/0 job:'lctl.0' uid:0 gid:0 projid:4294967295 [ 3981.217117] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 3981.233682] Lustre: Skipped 3 previous similar messages [ 3981.245549] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4005.799925] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 4005.823098] Lustre: Skipped 1 previous similar message [ 4021.280652] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4021.288207] Lustre: 88680:0:(service.c:2561:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff8c94f48f1f80 x1861425279119488/t0(0) o38->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1775197426 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4026.287535] LustreError: 88678:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4050.854164] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 4050.859714] Lustre: Skipped 4 previous similar messages [ 4066.352134] LustreError: 88678:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4066.372327] Lustre: 88678:0:(service.c:2561:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff8c94f48f0a80 x1861425279121664/t0(0) o38->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1775197471 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4071.344696] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 4071.351364] Lustre: Skipped 1 previous similar message [ 4071.354721] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4095.904860] Lustre: lustre-MDT0000: Export ffff8c94c57fc800 already connecting from 192.168.202.8@tcp [ 4095.911863] Lustre: Skipped 4 previous similar messages [ 4111.392918] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4111.401349] Lustre: 88680:0:(service.c:2561:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff8c94fd5e1880 x1861425279123840/t0(0) o38->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1775197516 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4116.385471] LustreError: 88678:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4156.432178] LustreError: 88678:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4156.447932] Lustre: 88678:0:(service.c:2561:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff8c94db43c700 x1861425279126016/t0(0) o38->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1775197561 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4161.441112] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4169.264195] LustreError: 88680:0:(ldlm_lib.c:1419:target_handle_connect()) cfs_fail_timeout interrupted [ 4174.904522] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 02:26:38 (1775197598) [ 4178.450233] LustreError: 92428:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4178.455722] LustreError: 92428:0:(osd_handler.c:720:osd_ro()) Skipped 6 previous similar messages [ 4179.587411] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4183.696920] Lustre: Failing over lustre-MDT0000 [ 4183.904985] Lustre: server umount lustre-MDT0000 complete [ 4192.284294] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4192.295401] LustreError: Skipped 7 previous similar messages [ 4192.681294] Lustre: *** cfs_fail_loc=712, val=0*** [ 4192.685693] 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 [ 4192.698885] LustreError: 33967:0:(service.c:1390:ptlrpc_check_req()) @@@ Invalid replay without recovery req@ffff8c94d2d88380 x1861425306216704/t0(0) o400->lustre-MDT0000-mdtlov_UUID@0@lo:0/0 lens 224/0 e 0 to 0 dl 0 ref 1 fl New:/2c0/ffffffff rc 0/-1 job:'ptlrpcd_rcv.0' uid:0 gid:0 projid:4294967295 [ 4192.699858] Lustre: Skipped 18 previous similar messages [ 4193.086947] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4193.089748] Lustre: lustre-MDT0000: Aborting client recovery [ 4193.093874] Lustre: Skipped 3 previous similar messages [ 4193.102516] LustreError: 93048:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 4193.108471] Lustre: 93099:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4193.112948] Lustre: 93099:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 4193.117534] Lustre: 93099:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4@ [ 4193.125528] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 4193.194372] Lustre: lustre-MDT0000-osd: cancel update llog [0x2000182d0:0x1:0x0] [ 4193.361824] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2913) [ 4193.368036] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2945) [ 4197.859250] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4197.871959] Lustre: Skipped 19 previous similar messages [ 4198.428099] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4206.647151] Lustre: Failing over lustre-MDT0000 [ 4207.186495] Lustre: server umount lustre-MDT0000 complete [ 4234.726747] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a2dc6da [ 4240.008797] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4248.482719] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4248.486498] Lustre: Skipped 3 previous similar messages [ 4248.526116] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4248.531787] Lustre: Skipped 3 previous similar messages [ 4248.555631] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2977) [ 4248.556096] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2945) [ 4252.106319] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4254.183483] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4264.469986] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 02:28:08 (1775197688) [ 4264.587648] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 4264.597752] Lustre: Skipped 2 previous similar messages [ 4273.507121] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 02:28:17 (1775197697) [ 4274.309145] Lustre: *** cfs_fail_loc=122, val=2147483648*** [ 4274.311845] LustreError: 93972:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94e4a32a00 x1861425279184384/t0(0) o700->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:185/0 lens 264/248 e 0 to 0 dl 1775197710 ref 1 fl Interpret:/200/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:4294967295 [ 4294.490988] Lustre: Failing over lustre-MDT0000 [ 4295.016954] Lustre: server umount lustre-MDT0000 complete [ 4322.151537] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a2dcb09 [ 4322.207076] LustreError: 95514:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4322.222684] LustreError: 95514:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 4323.598441] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2979 to 0x240000400:3009) [ 4323.612734] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2947 to 0x280000400:2977) [ 4327.482932] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4335.881430] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4337.435850] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4347.825938] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 02:29:32 (1775197772) [ 4350.303032] Lustre: Failing over lustre-OST0000 [ 4350.383229] Lustre: server umount lustre-OST0000 complete [ 4352.935164] LustreError: 14001:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4353.504813] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4353.519097] LustreError: Skipped 3 previous similar messages [ 4358.060064] LustreError: 33974:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4358.083070] LustreError: 33974:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 4374.070948] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4383.224901] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 4384.863202] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4458.852811] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 02:31:22 (1775197882) [ 4463.719991] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4466.382542] Lustre: Failing over lustre-MDT0000 [ 4466.748996] Lustre: server umount lustre-MDT0000 complete [ 4485.984156] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775197895/real 1775197895] req@ffff8c94c5f77480 x1861425306292480/t0(0) o400->MGC192.168.202.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1775197911 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4486.030914] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 4497.241978] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4497.246309] Lustre: Skipped 4 previous similar messages [ 4498.992953] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3030 to 0x240000400:3073) [ 4498.996538] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2998 to 0x280000400:3041) [ 4502.086489] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4577.706885] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 02:33:20 (1775198000) [ 4580.469924] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 4580.476615] Lustre: Skipped 2 previous similar messages [ 4593.042500] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 02:33:36 (1775198016) [ 4596.780882] Lustre: Failing over lustre-MDT0000 [ 4597.263828] Lustre: server umount lustre-MDT0000 complete [ 4624.353905] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94d0512300 x1861425306330752/t0(0) o250->MGC192.168.202.108@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 [ 4626.369123] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 4626.373373] LustreError: 99910:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c93c67b1500 x1861425279305216/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:537/0 lens 328/344 e 0 to 0 dl 1775198062 ref 1 fl Complete:/240/0 rc 0/0 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 4630.265986] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4641.698703] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 1:24 [ 4641.832619] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3053 to 0x280000400:3073) [ 4641.836373] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3084 to 0x240000400:3105) [ 4647.421594] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4649.722825] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4660.981382] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 02:34:44 (1775198084) [ 4663.878808] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4669.764477] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4671.786188] Lustre: Failing over lustre-MDT0000 [ 4672.098983] Lustre: server umount lustre-MDT0000 complete [ 4697.532471] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4704.936784] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3084 to 0x240000400:3137) [ 4704.940693] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3075 to 0x280000400:3105) [ 4709.432974] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4712.138450] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4725.806822] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 02:35:48 (1775198148) [ 4727.905168] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4733.755289] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4736.031516] Lustre: Failing over lustre-MDT0000 [ 4736.454831] Lustre: server umount lustre-MDT0000 complete [ 4768.503580] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4768.832681] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3084 to 0x240000400:3169) [ 4768.836021] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3107 to 0x280000400:3137) [ 4777.056448] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4779.108395] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4787.127967] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 02:36:51 (1775198211) [ 4788.836042] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4790.957150] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4793.981925] LustreError: 103971:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4793.995084] LustreError: 103971:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 4794.921702] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4797.524848] Lustre: Failing over lustre-MDT0000 [ 4797.990408] Lustre: server umount lustre-MDT0000 complete [ 4815.330509] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4815.337916] 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 [ 4815.357033] LustreError: Skipped 6 previous similar messages [ 4815.413674] Lustre: Skipped 15 previous similar messages [ 4825.568740] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c93c4a6d880 x1861425306385152/t0(0) o250->MGC192.168.202.108@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 [ 4826.710774] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4826.717804] Lustre: Skipped 9 previous similar messages [ 4831.213850] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3084 to 0x240000400:3201) [ 4831.214068] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3169) [ 4831.678451] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4840.612827] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4840.621032] Lustre: Skipped 18 previous similar messages [ 4845.255156] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 02:37:49 (1775198269) [ 4847.741641] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4847.743594] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 4847.752685] LustreError: 104528:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94fbaa5f80 x1861425279357696/t257698037777(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:3/0 lens 392/456 e 0 to 0 dl 1775198283 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4850.848587] Lustre: Failing over lustre-MDT0000 [ 4851.173184] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4851.396759] Lustre: server umount lustre-MDT0000 complete [ 4874.157844] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4874.167453] Lustre: Skipped 7 previous similar messages [ 4874.302414] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4874.314664] Lustre: Skipped 7 previous similar messages [ 4874.364988] Lustre: 105765:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94d229f800 x1861425279357696/t257698037777(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:30/0 lens 392/456 e 0 to 0 dl 1775198310 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4874.370037] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3084 to 0x240000400:3233) [ 4874.398193] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3171 to 0x280000400:3201) [ 4874.703730] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4884.550848] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4886.358389] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4896.950282] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 02:38:40 (1775198320) [ 4898.460328] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4898.470357] LustreError: 105763:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94f4fbbb80 x1861425279371776/t261993005072(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:54/0 lens 504/448 e 0 to 0 dl 1775198334 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4904.353526] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4906.377883] Lustre: Failing over lustre-MDT0000 [ 4906.654480] Lustre: server umount lustre-MDT0000 complete [ 4933.537191] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4939.324985] Lustre: 107291:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fc0c4000 x1861425279371776/t261993005072(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:95/0 lens 504/2880 e 0 to 0 dl 1775198375 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4939.329946] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3265) [ 4939.330533] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3171 to 0x280000400:3233) [ 4943.426570] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4945.300876] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4954.694996] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 02:39:38 (1775198378) [ 4956.334373] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4956.348843] LustreError: 107291:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94d0510000 x1861425279385728/t266287972368(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:112/0 lens 504/448 e 0 to 0 dl 1775198392 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4958.441677] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4962.576474] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4964.650266] Lustre: Failing over lustre-MDT0000 [ 4964.779662] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.8@tcp (stopping) [ 4964.784838] Lustre: Skipped 1 previous similar message [ 4964.936225] Lustre: server umount lustre-MDT0000 complete [ 4985.517887] Lustre: 108811:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94c4691c00 x1861425279385728/t266287972368(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:141/0 lens 504/2880 e 0 to 0 dl 1775198421 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4985.524840] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3265) [ 4985.526839] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3297) [ 4985.547534] Lustre: 108811:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 1 previous similar message [ 4988.510774] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5000.450451] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 02:40:24 (1775198424) [ 5001.856734] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5001.870364] Lustre: Skipped 1 previous similar message [ 5001.886217] LustreError: 108813:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c93c4a6f800 x1861425279397888/t270582939664(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:157/0 lens 504/448 e 0 to 0 dl 1775198437 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5001.920772] LustreError: 108813:0:(ldlm_lib.c:3326:target_send_reply_msg()) Skipped 1 previous similar message [ 5004.010850] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 5009.824338] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5011.991771] Lustre: Failing over lustre-MDT0000 [ 5012.327063] Lustre: server umount lustre-MDT0000 complete [ 5035.016379] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5042.771956] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3267 to 0x280000400:3297) [ 5042.772450] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3329) [ 5042.789481] Lustre: 110297:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fc0c6680 x1861425279397888/t270582939664(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:198/0 lens 504/2880 e 0 to 0 dl 1775198478 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5051.911794] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 02:41:15 (1775198475) [ 5053.403624] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 5055.368524] Lustre: *** cfs_fail_loc=13b, val=315*** [ 5055.376618] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 5055.378612] LustreError: 110300:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94c4693800 x1861425279410304/t274877906960(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:211/0 lens 392/456 e 0 to 0 dl 1775198491 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5060.122230] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5062.572104] Lustre: Failing over lustre-MDT0000 [ 5062.950708] Lustre: server umount lustre-MDT0000 complete [ 5081.057063] LustreError: 111684:0:(ldlm_lib.c:1179: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. [ 5081.077653] LustreError: 111684:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 5085.630912] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5086.375276] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775198495/real 1775198495] req@ffff8c94fd47a680 x1861425306463488/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775198511 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5086.405748] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 56 previous similar messages [ 5094.587848] Lustre: 111687:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94cdd3ea00 x1861425279410304/t274877906960(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:250/0 lens 392/456 e 0 to 0 dl 1775198530 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5094.603034] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3267 to 0x280000400:3329) [ 5094.607120] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3331 to 0x240000400:3361) [ 5107.361722] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 02:42:11 (1775198531) [ 5108.792862] Lustre: *** cfs_fail_loc=12b, val=2147483991*** [ 5108.802025] LustreError: 111686:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94fd1fdc00 x1861425279420416/t279172874255(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:264/0 lens 664/608 e 0 to 0 dl 1775198544 ref 1 fl Interpret:/600/0 rc 301/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5125.031195] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnecting [ 5125.046752] Lustre: Skipped 1 previous similar message [ 5125.080248] Lustre: 111682:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fbaa6300 x1861425279420416/t279172874255(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:281/0 lens 664/3488 e 0 to 0 dl 1775198561 ref 1 fl Interpret:/602/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5132.552789] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 02:42:36 (1775198556) [ 5136.911647] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5138.717338] Lustre: Failing over lustre-MDT0000 [ 5138.966185] Lustre: server umount lustre-MDT0000 complete [ 5156.788105] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5156.791317] Lustre: Skipped 9 previous similar messages [ 5161.367636] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5166.117935] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3331 to 0x240000400:3393) [ 5166.134152] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3331 to 0x280000400:3361) [ 5170.469643] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5172.229486] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5192.998035] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 02:43:36 (1775198616) [ 5198.718453] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5201.413747] Lustre: Failing over lustre-MDT0000 [ 5201.844557] Lustre: server umount lustre-MDT0000 complete [ 5234.489877] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5242.954294] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3363 to 0x280000400:3393) [ 5242.956887] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3331 to 0x240000400:3425) [ 5248.445764] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5250.235522] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5256.582299] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 5270.197131] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 02:44:53 (1775198693) [ 5324.180887] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5326.136332] Lustre: Failing over lustre-MDT0000 [ 5326.704791] Lustre: server umount lustre-MDT0000 complete [ 5356.515809] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94fae75c00 x1861425306539264/t0(0) o250->MGC192.168.202.108@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 [ 5364.119649] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5371.392409] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4705) [ 5371.400790] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4644 to 0x280000400:4673) [ 5376.189705] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5378.654493] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5451.956818] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 02:47:56 (1775198876) [ 5456.575902] LustreError: 118017:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5456.581621] LustreError: 118017:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 5457.729318] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5459.913784] Lustre: Failing over lustre-MDT0000 [ 5460.163634] Lustre: server umount lustre-MDT0000 complete [ 5479.515962] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5479.522731] LustreError: Skipped 8 previous similar messages [ 5479.811689] 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 [ 5479.824501] Lustre: Skipped 18 previous similar messages [ 5480.211469] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5480.231248] Lustre: Skipped 8 previous similar messages [ 5480.429389] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5480.445619] Lustre: Skipped 7 previous similar messages [ 5485.026935] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5485.032512] Lustre: Skipped 17 previous similar messages [ 5486.517432] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5488.828352] Lustre: lustre-MDT0000: Recovery over after 0:08, of 2 clients 2 recovered and 0 were evicted. [ 5488.831416] Lustre: Skipped 7 previous similar messages [ 5488.867961] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4644 to 0x280000400:4705) [ 5488.880821] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4707 to 0x240000400:4737) [ 5495.716650] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5498.155165] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5508.857636] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid [ 5511.238977] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 5520.130347] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 02:49:03 (1775198943) [ 5527.412804] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 5546.048054] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5546.056443] Lustre: Skipped 1 previous similar message [ 5546.063060] LustreError: 118576:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94f48c7c50 x1861425282206848/t296352743435(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:702/0 lens 66040/440 e 0 to 0 dl 1775198982 ref 1 fl Interpret:/600/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5562.300444] Lustre: 118575:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fd0d2680 x1861425282206848/t296352743435(0) o36->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:718/0 lens 66040/440 e 0 to 0 dl 1775198998 ref 1 fl Interpret:/602/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5577.242881] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 5579.500268] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 02:50:03 (1775199003) [ 5592.240320] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5595.694803] Lustre: Failing over lustre-MDT0000 [ 5597.669359] LustreError: 118575:0:(ldlm_lib.c:1179: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. [ 5597.696278] LustreError: 118575:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 5598.136199] Lustre: server umount lustre-MDT0000 complete [ 5623.717438] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.8@tcp (not set up) [ 5623.721300] Lustre: Skipped 2 previous similar messages [ 5626.983309] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4807 to 0x280000400:4833) [ 5626.992090] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4838 to 0x240000400:4865) [ 5629.694708] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5639.435851] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5641.608784] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5652.675892] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 02:51:16 (1775199076) [ 5678.313661] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5694.744445] Lustre: Failing over lustre-OST0000 [ 5694.915376] Lustre: server umount lustre-OST0000 complete [ 5695.466652] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 5695.475705] LustreError: 33967:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5703.648714] LustreError: 33967:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5703.671277] LustreError: 33967:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 5719.404568] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5734.163502] Lustre: Failing over lustre-OST0000 [ 5734.181807] LustreError: 123190:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 5734.188503] Lustre: 122640:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5734.197657] Lustre: 122640:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 5734.215398] Lustre: 122640:0:(ldlm_lib.c:1897:abort_req_replay_queue()) @@@ aborted: req@ffff8c93c8420000 x1861425307293824/t0(17179870639) o6->lustre-MDT0000-mdtlov_UUID@0@lo:140/0 lens 544/0 e 2 to 0 dl 1775199175 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 5734.237694] LustreError: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -19 [ 5734.237750] LustreError: 122640:0:(ofd_obd.c:1325:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 5734.243646] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 5734.382114] Lustre: server umount lustre-OST0000 complete [ 5739.501808] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5739.521528] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 5763.646497] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5768.332852] LustreError: 3321:0:(client.c:3419:ptlrpc_replay_interpret()) @@@ status 0, old was -19 req@ffff8c94c469a680 x1861425307293824/t17179870639(17179870639) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 3 to 0 dl 1775199210 ref 2 fl Interpret:RQU/204/0 rc 0/0 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 5775.357991] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5777.789305] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5821.029880] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 02:54:04 (1775199244) [ 5824.877506] Lustre: Failing over lustre-MDT0000 [ 5825.511777] Lustre: server umount lustre-MDT0000 complete [ 5845.254358] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5845.264958] Lustre: Skipped 6 previous similar messages [ 5846.112425] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775199254/real 1775199254] req@ffff8c94f4a2f800 x1861425307430144/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775199270 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5846.144531] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 5846.745587] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5249) [ 5846.745622] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5281) [ 5850.792826] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5866.552231] Lustre: Failing over lustre-MDT0000 [ 5867.116361] Lustre: server umount lustre-MDT0000 complete [ 5896.186760] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a33759f [ 5899.032072] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5313) [ 5899.039801] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5281) [ 5904.129166] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5913.637286] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5915.723143] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5926.020594] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 02:55:49 (1775199349) [ 5941.790714] Lustre: Failing over lustre-OST0000 [ 5942.030176] Lustre: server umount lustre-OST0000 complete [ 5942.243951] LustreError: 33972:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5942.266214] LustreError: 33972:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 5971.920659] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5981.338592] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5984.088926] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5997.206750] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 02:57:01 (1775199421) [ 5999.559352] Lustre: Failing over lustre-MDT0000 [ 6000.189882] Lustre: server umount lustre-MDT0000 complete [ 6014.827484] Lustre: *** cfs_fail_loc=605, val=0*** [ 6014.829057] LustreError: 128616:0:(llog_obd.c:190:llog_setup()) MGS: ctxt 0 lop_setup=ffffffffc1136680 failed: rc = -95 [ 6014.845190] LustreError: 128616:0:(obd_config.c:843:class_setup()) setup MGS failed (-95) [ 6014.860469] LustreError: 128616:0:(obd_mount.c:250:lustre_start_simple()) MGS setup error -95 [ 6014.885500] LustreError: 128616:0:(tgt_mount.c:114:server_deregister_mount()) MGS not registered [ 6014.896192] LustreError: Failed to start MGS 'MGS' (-95). Is the 'mgs' module loaded? [ 6014.908845] LustreError: 128616:0:(tgt_mount.c:2063:server_put_super()) no obd lustre-MDT0000 [ 6015.158597] Lustre: server umount lustre-MDT0000 complete [ 6015.160787] LustreError: 128616:0:(super25.c:184:lustre_fill_super()) llite: Unable to mount : rc = -95 [ 6032.604159] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5315 to 0x240000400:5345) [ 6032.607769] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5283 to 0x280000400:5313) [ 6037.037068] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6048.492439] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 02:57:51 (1775199471) [ 6053.989522] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6058.391651] Lustre: Failing over lustre-MDT0000 [ 6058.715237] Lustre: server umount lustre-MDT0000 complete [ 6087.656380] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xe783d857a338280 [ 6087.666882] Lustre: MGC192.168.202.108@tcp: Connection restored to 0@lo (at 0@lo) [ 6087.669463] Lustre: Skipped 12 previous similar messages [ 6088.181995] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6088.193410] Lustre: Skipped 7 previous similar messages [ 6093.441563] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6102.947931] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 6102.950933] Lustre: Skipped 7 previous similar messages [ 6102.962124] Lustre: *** cfs_fail_loc=707, val=0*** [ 6119.376875] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 6120.544548] Lustre: lustre-MDT0000: Recovery over after 0:18, of 1 clients 1 recovered and 0 were evicted. [ 6120.553944] Lustre: Skipped 7 previous similar messages [ 6120.617025] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5359 to 0x240000400:5377) [ 6120.644973] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5326 to 0x280000400:5345) [ 6129.409856] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6132.055859] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6146.705418] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 02:59:29 (1775199569) [ 6181.322904] LustreError: 130216:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94c46e7480 x1861425283089024/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:582/0 lens 664/0 e 0 to 0 dl 1775199617 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6181.355702] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 11000ms [ 6192.368968] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6192.399045] LustreError: 130218:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94fc885c00 x1861425283090048/t0(0) o35->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:599/0 lens 392/0 e 0 to 0 dl 1775199634 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6196.141954] LustreError: 130214:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94f626d500 x1861425283096320/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:604/0 lens 576/0 e 0 to 0 dl 1775199639 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 6196.204707] LustreError: 130214:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 27 previous similar messages [ 6202.351199] LustreError: 33972:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94c4692300 x1861425307526784/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:603/0 lens 544/0 e 0 to 0 dl 1775199638 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-1-0.0' uid:0 gid:0 projid:4294967295 [ 6202.379543] LustreError: 33972:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 28 previous similar messages [ 6216.737208] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 03:00:40 (1775199640) [ 6252.848229] LustreError: 33796:0:(tgt_handler.c:2787:tgt_brw_write()) cfs_fail_timeout id 224 sleeping for 11000ms [ 6263.872242] LustreError: 33796:0:(tgt_handler.c:2787:tgt_brw_write()) cfs_fail_timeout id 224 awake [ 6277.771639] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 03:01:41 (1775199701) [ 6311.431743] LustreError: 130216:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c93cd461f80 x1861425283115904/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:712/0 lens 576/0 e 0 to 0 dl 1775199747 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6311.483082] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 5000ms [ 6316.520181] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6320.134484] LustreError: 130214:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94fb7c1880 x1861425283137408/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:721/0 lens 576/0 e 0 to 0 dl 1775199756 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6320.183619] LustreError: 130214:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 99 previous similar messages [ 6320.200133] LustreError: 130214:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 10000ms [ 6330.272154] LustreError: 130214:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6354.849511] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 03:02:57 (1775199777) [ 6454.461228] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 03:04:38 (1775199878) [ 6487.954898] LustreError: 131786:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94db556680 x1861425283196032/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:134/0 lens 576/0 e 0 to 0 dl 1775199924 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6487.994567] LustreError: 131786:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 121 previous similar messages [ 6488.008947] LustreError: 131786:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6488.432166] LustreError: 131786:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6504.656158] LustreError: 131786:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6504.677638] LustreError: 131786:0:(service.c:2538:ptlrpc_server_handle_request()) Skipped 36 previous similar messages [ 6520.397986] LustreError: 130216:0:(service.c:2537:ptlrpc_server_handle_request()) @@@ HIT req@ffff8c94c469a680 x1861425283213952/t0(0) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:166/0 lens 576/0 e 0 to 0 dl 1775199956 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 6520.431367] LustreError: 130216:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 74 previous similar messages [ 6520.445097] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6520.456120] LustreError: 130216:0:(service.c:2538:ptlrpc_server_handle_request()) Skipped 74 previous similar messages [ 6545.749554] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 03:06:09 (1775199969) [ 6586.638594] Lustre: DEBUG MARKER: phase 2 [ 6609.860853] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 03:07:13 (1775200033) [ 6706.762411] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 03:08:50 (1775200130) [ 6708.576165] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 6710.558391] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 1mdts recovery; 1 clients ========================================================== 03:08:54 (1775200134) [ 6715.511706] Lustre: DEBUG MARKER: Started rundbench load pid=127208 ... [ 6720.513936] LustreError: 136943:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6720.520607] LustreError: 136943:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 6721.566805] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6724.806676] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 6727.780707] Lustre: Failing over lustre-MDT0000 [ 6728.089494] Lustre: server umount lustre-MDT0000 complete [ 6747.805848] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6747.821327] LustreError: Skipped 5 previous similar messages [ 6748.069618] LustreError: 137540:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6748.098826] LustreError: 137540:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 6748.410382] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6748.427782] Lustre: Skipped 12 previous similar messages [ 6748.560057] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775200157/real 1775200157] req@ffff8c94fd461880 x1861425307668352/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775200173 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6748.598605] Lustre: 3323:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 35 previous similar messages [ 6748.817030] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6748.821603] Lustre: Skipped 4 previous similar messages [ 6749.040306] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6749.520616] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 6751.164425] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 6751.264979] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5477 to 0x240000400:5505) [ 6751.268909] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5424 to 0x280000400:5441) [ 6753.786991] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 6753.798905] Lustre: Skipped 2 previous similar messages [ 6755.603469] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6765.756410] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6768.134291] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6778.135307] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6781.821756] Lustre: DEBUG MARKER: test_70b fail mds1 2 times [ 6784.624994] Lustre: Failing over lustre-MDT0000 [ 6785.080144] Lustre: server umount lustre-MDT0000 complete [ 6821.533877] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6824.855141] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5466 to 0x280000400:5505) [ 6824.861664] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5530 to 0x240000400:5569) [ 6830.317672] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6832.233641] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6869.639314] Lustre: DEBUG MARKER: == replay-single test 70c: tar 1mdts recovery ============ 03:11:32 (1775200292) [ 6995.919265] LustreError: 139851:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6995.926375] LustreError: 139851:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 6997.324026] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7010.683457] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 7013.429386] Lustre: Failing over lustre-MDT0000 [ 7013.933911] Lustre: server umount lustre-MDT0000 complete [ 7030.752880] 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 [ 7030.759876] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7030.774622] Lustre: Skipped 3 previous similar messages [ 7030.802739] LustreError: Skipped 1 previous similar message [ 7039.968716] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94c5f2ed80 x1861425308117504/t0(0) o250->MGC192.168.202.108@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 [ 7046.422672] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7061.134389] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6100 to 0x240000400:6145) [ 7061.149701] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6036 to 0x280000400:6081) [ 7066.818736] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 7069.154578] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7163.329591] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 1mdts recovery ========================================================== 03:16:27 (1775200587) [ 7165.411791] Lustre: DEBUG MARKER: SKIP: replay-single test_70d needs >= 2 MDTs [ 7167.545805] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 03:16:31 (1775200591) [ 7169.674413] Lustre: DEBUG MARKER: SKIP: replay-single test_70e needs >= 2 MDTs [ 7171.627104] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 03:16:35 (1775200595) [ 7179.052654] LustreError: 141667:0:(osd_handler.c:720:osd_ro()) lustre-OST0000: *** setting device osd-zfs read-only *** [ 7180.318190] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7183.020394] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 7184.918681] Lustre: Failing over lustre-OST0000 [ 7184.968145] Lustre: server umount lustre-OST0000 complete [ 7186.375629] LustreError: 14000:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7188.971477] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 7188.987402] Lustre: Skipped 1 previous similar message [ 7196.578231] LustreError: 33969:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7196.606288] LustreError: 33969:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 7210.502512] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7220.420654] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 7222.550362] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7234.692954] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7237.546398] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 7240.932812] Lustre: Failing over lustre-OST0000 [ 7241.228650] Lustre: server umount lustre-OST0000 complete [ 7241.698514] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7241.702512] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7241.725224] LustreError: 6572:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 7267.431664] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7275.781541] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 7277.951211] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7290.659331] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 03:18:34 (1775200714) [ 7292.565701] Lustre: DEBUG MARKER: SKIP: replay-single test_71a needs >= 2 MDTs [ 7294.647734] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 03:18:38 (1775200718) [ 7299.909673] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7302.845643] Lustre: Failing over lustre-MDT0000 [ 7303.189970] Lustre: server umount lustre-MDT0000 complete [ 7321.011251] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7326.347202] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7330.731168] Lustre: *** cfs_fail_loc=302, val=2147483648*** [ 7347.161085] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 7347.417753] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6224 to 0x280000400:6241) [ 7347.419609] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6288 to 0x240000400:6305) [ 7353.054615] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 7355.198653] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7366.334569] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 03:19:49 (1775200789) [ 7371.080739] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7374.395814] Lustre: Failing over lustre-MDT0000 [ 7374.834255] Lustre: server umount lustre-MDT0000 complete [ 7393.248259] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775200802/real 1775200802] req@ffff8c94c5f01f80 x1861425308489088/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1775200818 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7393.300128] Lustre: 3324:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 7403.490473] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94faa4bb80 x1861425308490880/t0(0) o250->MGC192.168.202.108@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 [ 7404.215277] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7404.221054] Lustre: Skipped 5 previous similar messages [ 7404.287479] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 7404.300909] Lustre: Skipped 5 previous similar messages [ 7409.383829] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7417.769598] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 7417.780545] Lustre: Skipped 5 previous similar messages [ 7417.856782] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 7417.858995] LustreError: 146750:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff8c94c5a48700 x1861425289334912/t335007449091(335007449091) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:308/0 lens 592/608 e 0 to 0 dl 1775200853 ref 1 fl Interpret:/604/0 rc 301/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7418.404711] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 7418.411035] Lustre: Skipped 9 previous similar messages [ 7434.195564] Lustre: lustre-MDT0000: Client 2c006eba-33df-4be9-9ce6-47a8d7dfedc4 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 7434.207504] Lustre: 146746:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff8c94fb583b80 x1861425289334912/t335007449091(335007449091) o101->2c006eba-33df-4be9-9ce6-47a8d7dfedc4@192.168.202.8@tcp:325/0 lens 592/3488 e 0 to 0 dl 1775200870 ref 1 fl Interpret:/606/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7434.400846] Lustre: lustre-MDT0000: Recovery over after 0:17, of 1 clients 1 recovered and 0 were evicted. [ 7434.403751] Lustre: Skipped 5 previous similar messages [ 7434.448083] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6288 to 0x240000400:6337) [ 7434.449421] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6243 to 0x280000400:6273) [ 7440.267486] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 7442.260487] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7452.305832] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 03:21:15 (1775200875) [ 7457.031855] Lustre: Failing over lustre-OST0000 [ 7457.117606] Lustre: server umount lustre-OST0000 complete [ 7459.304447] LustreError: 14001:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7459.313610] LustreError: 14001:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 7461.582373] Lustre: Failing over lustre-MDT0000 [ 7462.011514] Lustre: server umount lustre-MDT0000 complete [ 7490.016865] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94c12a8700 x1861425308510976/t0(0) o250->MGC192.168.202.108@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 [ 7490.601819] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6243 to 0x280000400:6305) [ 7496.204669] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7505.888615] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6288 to 0x240000400:6369) [ 7512.643539] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7526.026601] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 03:22:29 (1775200949) [ 7527.875465] Lustre: DEBUG MARKER: SKIP: replay-single test_80a needs >= 2 MDTs [ 7530.158148] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 03:22:33 (1775200953) [ 7532.377560] Lustre: DEBUG MARKER: SKIP: replay-single test_80b needs >= 2 MDTs [ 7534.594740] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 03:22:38 (1775200958) [ 7536.442726] Lustre: DEBUG MARKER: SKIP: replay-single test_80c needs >= 2 MDTs [ 7538.728325] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 03:22:42 (1775200962) [ 7540.866990] Lustre: DEBUG MARKER: SKIP: replay-single test_80d needs >= 2 MDTs [ 7543.201628] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 03:22:46 (1775200966) [ 7545.414601] Lustre: DEBUG MARKER: SKIP: replay-single test_80e needs >= 2 MDTs [ 7548.005144] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 03:22:51 (1775200971) [ 7550.088767] Lustre: DEBUG MARKER: SKIP: replay-single test_80f needs >= 2 MDTs [ 7552.277819] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 03:22:56 (1775200976) [ 7554.287464] Lustre: DEBUG MARKER: SKIP: replay-single test_80g needs >= 2 MDTs [ 7556.595622] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 03:23:00 (1775200980) [ 7558.757900] Lustre: DEBUG MARKER: SKIP: replay-single test_80h needs >= 2 MDTs [ 7560.580326] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 03:23:04 (1775200984) [ 7563.065872] Lustre: DEBUG MARKER: SKIP: replay-single test_81a needs >= 2 MDTs [ 7565.309750] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 03:23:08 (1775200988) [ 7567.379262] Lustre: DEBUG MARKER: SKIP: replay-single test_81b needs >= 2 MDTs [ 7569.487227] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 03:23:13 (1775200993) [ 7571.359755] Lustre: DEBUG MARKER: SKIP: replay-single test_81c needs >= 2 MDTs [ 7573.649491] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 03:23:17 (1775200997) [ 7575.558144] Lustre: DEBUG MARKER: SKIP: replay-single test_81d needs >= 2 MDTs [ 7578.046765] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 03:23:21 (1775201001) [ 7580.035906] Lustre: DEBUG MARKER: SKIP: replay-single test_81e needs >= 2 MDTs [ 7582.279700] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 03:23:25 (1775201005) [ 7584.522450] Lustre: DEBUG MARKER: SKIP: replay-single test_81f needs >= 2 MDTs [ 7586.849157] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 03:23:30 (1775201010) [ 7588.715710] Lustre: DEBUG MARKER: SKIP: replay-single test_81g needs >= 2 MDTs [ 7590.856895] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 03:23:34 (1775201014) [ 7592.611654] Lustre: DEBUG MARKER: SKIP: replay-single test_81h needs >= 2 MDTs [ 7594.987793] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 03:23:38 (1775201018) [ 7597.313958] Lustre: 151161:0:(genops.c:1793:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 878ac8d6-be4e-4aac-b121-fdc5cfc63df1 at adminstrative request [ 7609.726481] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 03:23:53 (1775201033) [ 7617.558402] Lustre: Failing over lustre-MDT0000 [ 7618.234198] Lustre: server umount lustre-MDT0000 complete [ 7634.720182] 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 [ 7634.730411] Lustre: Skipped 7 previous similar messages [ 7635.745135] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7635.757399] LustreError: Skipped 2 previous similar messages [ 7645.920787] LustreError: 3321:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c94c5f00000 x1861425308545792/t0(0) o250->MGC192.168.202.108@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 [ 7649.126146] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6421 to 0x240000400:6465) [ 7649.126448] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6357 to 0x280000400:6401) [ 7651.735074] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7660.005764] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 7661.880433] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7672.957439] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 03:24:56 (1775201096) [ 7695.435784] Lustre: Failing over lustre-OST0000 [ 7695.636586] Lustre: server umount lustre-OST0000 complete [ 7695.852694] LustreError: 6574:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7695.872730] LustreError: 6574:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 7722.317268] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7731.830991] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 7733.528157] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7746.459461] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 03:26:10 (1775201170) [ 7753.683414] Lustre: Failing over lustre-MDT0000 [ 7754.083648] Lustre: server umount lustre-MDT0000 complete [ 7762.026419] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6357 to 0x280000400:6433) [ 7762.044437] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6566 to 0x240000400:6593) [ 7766.323371] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7777.969356] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 03:26:41 (1775201201) [ 7782.537638] LustreError: 155219:0:(osd_handler.c:720:osd_ro()) lustre-OST0000: *** setting device osd-zfs read-only *** [ 7782.542236] LustreError: 155219:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 7783.664285] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7786.870989] Lustre: Failing over lustre-OST0000 [ 7786.970649] Lustre: server umount lustre-OST0000 complete [ 7787.494442] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7813.316561] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7822.157553] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 7824.192167] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7834.545292] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 03:27:38 (1775201258) [ 7840.189503] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7844.592580] Lustre: Failing over lustre-OST0000 [ 7844.662605] Lustre: server umount lustre-OST0000 complete [ 7845.357419] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7845.372506] LustreError: 10097:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7845.390443] LustreError: 10097:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 15 previous similar messages [ 7870.272823] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7879.535718] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 7881.902132] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7891.790552] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 03:28:35 (1775201315) [ 7896.573411] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7901.259961] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7908.129901] Lustre: Failing over lustre-MDT0000 [ 7908.599366] Lustre: server umount lustre-MDT0000 complete [ 7912.885464] LustreError: 33976:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1775201337 with bad export cookie 1042650957226852954 [ 7922.145659] Lustre: Failing over lustre-OST0000 [ 7922.224212] Lustre: server umount lustre-OST0000 complete [ 7964.115538] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7973.630300] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6474 to 0x280000400:6497) [ 7988.760108] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7993.371369] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6595 to 0x240000400:6625) [ 8007.878829] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 03:30:31 (1775201431) [ 8025.727906] Lustre: Failing over lustre-OST0000 [ 8027.914363] Lustre: server umount lustre-OST0000 complete [ 8029.153793] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 8032.252601] Lustre: Failing over lustre-MDT0000 [ 8032.556193] Lustre: server umount lustre-MDT0000 complete [ 8050.144414] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775201459/real 1775201459] req@ffff8c94c5a4a680 x1861425308662912/t0(0) o400->MGC192.168.202.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1775201475 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 8050.197585] Lustre: 3322:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 29 previous similar messages [ 8061.260043] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8061.262598] Lustre: Skipped 9 previous similar messages [ 8061.394676] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 8061.406091] Lustre: Skipped 7 previous similar messages [ 8065.992343] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8075.200434] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 8075.207511] Lustre: Skipped 7 previous similar messages [ 8075.238554] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 8075.247840] Lustre: Skipped 12 previous similar messages [ 8075.459882] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 8075.479817] Lustre: Skipped 7 previous similar messages [ 8075.554117] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6474 to 0x280000400:6529) [ 8089.944808] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8092.668678] Lustre: lustre-OST0000: Denying connection for new client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 8092.686516] Lustre: Skipped 11 previous similar messages [ 8102.819730] Lustre: lustre-OST0000: Denying connection for new client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:50 [ 8102.862040] Lustre: Skipped 1 previous similar message [ 8123.294572] Lustre: lustre-OST0000: Denying connection for new client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:30 [ 8123.311368] Lustre: Skipped 3 previous similar messages [ 8153.507568] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 8153.514760] Lustre: 162481:0:(genops.c:1620:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client 1c332005-4e9d-4723-9edd-28c617d41039@ [ 8153.536191] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 8153.705666] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6636 to 0x240000400:6657) [ 8157.716644] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 54 sec [ 8172.498412] Lustre: DEBUG MARKER: free_before: 7520256 free_after: 7520256 [ 8179.771413] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 03:33:23 (1775201603) [ 8185.419293] Lustre: Failing over lustre-OST0000 [ 8185.547036] Lustre: server umount lustre-OST0000 complete [ 8189.410419] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 8189.428392] LustreError: 33972:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8189.439675] LustreError: 33972:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 31 previous similar messages [ 8212.324330] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8224.489107] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 03:34:08 (1775201648) [ 8228.701961] Lustre: Failing over lustre-OST0000 [ 8228.819597] Lustre: server umount lustre-OST0000 complete [ 8249.035485] LustreError: 165336:0:(ldlm_lib.c:2885:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 40000ms [ 8249.043743] LustreError: 165336:0:(ldlm_lib.c:2885:target_recovery_thread()) Skipped 43 previous similar messages [ 8253.591777] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8254.948961] Lustre: *** cfs_fail_loc=715, val=40*** [ 8264.607559] Lustre: lustre-OST0000: Client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp) reconnected, waiting for 2 clients in recovery for 1:24 [ 8265.188199] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 1:24 [ 8270.819441] Lustre: *** cfs_fail_loc=715, val=40*** [ 8270.828423] Lustre: Skipped 1 previous similar message [ 8271.840236] Lustre: *** cfs_fail_loc=715, val=40*** [ 8280.991517] Lustre: lustre-OST0000: Client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp) reconnected, waiting for 2 clients in recovery for 1:08 [ 8287.200395] Lustre: *** cfs_fail_loc=715, val=40*** [ 8289.112648] LustreError: 165336:0:(ldlm_lib.c:2885:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8289.116328] LustreError: 165336:0:(ldlm_lib.c:2885:target_recovery_thread()) Skipped 81 previous similar messages [ 8294.543881] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 8296.866159] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 8308.958319] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 03:35:32 (1775201732) [ 8314.407470] Lustre: Failing over lustre-MDT0000 [ 8314.771298] Lustre: server umount lustre-MDT0000 complete [ 8332.256119] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8332.259086] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 8332.265340] LustreError: Skipped 3 previous similar messages [ 8332.294498] Lustre: Skipped 11 previous similar messages [ 8344.995505] LustreError: 166779:0:(ldlm_lib.c:2885:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 80000ms [ 8349.379112] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8351.203505] Lustre: *** cfs_fail_loc=715, val=80*** [ 8351.207853] Lustre: Skipped 1 previous similar message [ 8361.381809] Lustre: lustre-MDT0000: Client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 8361.424426] Lustre: Skipped 1 previous similar message [ 8367.584733] Lustre: *** cfs_fail_loc=715, val=80*** [ 8376.736705] Lustre: lustre-MDT0000: Client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:37 [ 8393.119974] Lustre: lustre-MDT0000: Client 30a95f04-d2f5-414b-bb0d-8c590de9d557 (at 192.168.202.8@tcp) reconnected, waiting for 1 clients in recovery for 0:21 [ 8399.328262] Lustre: *** cfs_fail_loc=715, val=80*** [ 8399.338058] Lustre: Skipped 1 previous similar message [ 8424.862042] Lustre: lustre-MDT0000: Recovery already passed deadline 0:10. If you do not want to wait more, you may force taget eviction via 'lctl --device lustre-MDT0000 abort_recovery. [ 8425.008364] LustreError: 166779:0:(ldlm_lib.c:2885:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8425.159542] Lustre: 166779:0:(ldlm_lib.c:2931:target_recovery_thread()) too long recovery - read logs [ 8425.184430] LustreError: dumping log to /tmp/lustre-log.1775201850.166779 [ 8425.389965] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6671 to 0x240000400:6689) [ 8425.390202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6542 to 0x280000400:6561) [ 8430.625452] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 8432.420335] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 8443.160498] Lustre: DEBUG MARKER: == replay-single test complete, duration 8176 sec ======== 03:37:46 (1775201866) [ 8445.573888] Lustre: DEBUG MARKER: === replay-single: start cleanup 03:37:48 (1775201868) === [ 8459.022226] Lustre: DEBUG MARKER: === replay-single: finish cleanup 03:38:02 (1775201882) === [ 8489.279514] Lustre: server umount lustre-MDT0000 complete [ 8493.917972] LustreError: 11024:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1775201918 with bad export cookie 1042650957226865365 [ 8503.392878] Lustre: server umount lustre-OST0000 complete [ 8508.301345] Lustre: server umount lustre-OST0001 complete [ 8522.128991] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing unload_modules_local [ 8525.243496] Key type lgssc unregistered [ 8525.550755] LNet: 168803:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8525.557285] LNetError: 168803:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 8525.571384] LNet: Removed LNI 192.168.202.108@tcp [ 8526.341259] Key type .llcrypt unregistered [ 8526.342966] Key type ._llcrypt unregistered