[ 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.16.2-1.fc38 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 500677934 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 0x000f5b30-0x000f5b3f] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5950 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1BB7 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1A53 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001A13 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1AC7 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1B57 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1B8F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1a53-0xbffe1ac6] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1a52] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1ac7-0xbffe1b56] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1b57-0xbffe1b8e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1b8f-0xbffe1bb6] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.002400] x2apic enabled [ 0.003009] Switched APIC routing to physical x2apic. [ 0.004016] kvm-guest: setup PV IPIs [ 0.007614] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008020] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010007] pid_max: default: 32768 minimum: 301 [ 0.011145] LSM: Security Framework initializing [ 0.012000] Yama: becoming mindful. [ 0.012052] SELinux: Initializing. [ 0.013076] *** VALIDATE selinux *** [ 0.021705] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026414] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.027173] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028104] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029110] *** VALIDATE tmpfs *** [ 0.030401] *** VALIDATE proc *** [ 0.031215] *** VALIDATE cgroup *** [ 0.032009] *** VALIDATE cgroup2 *** [ 0.034038] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035000] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035014] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037033] Spectre V2 : User space: Vulnerable [ 0.038007] Speculative Store Bypass: Vulnerable [ 0.041123] debug: unmapping init [mem 0xffffffffb1259000-0xffffffffb1260fff] [ 0.043183] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044743] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045027] ... version: 2 [ 0.046017] ... bit width: 48 [ 0.047019] ... generic registers: 4 [ 0.048019] ... value mask: 0000ffffffffffff [ 0.049016] ... max period: 00007fffffffffff [ 0.050011] ... fixed-purpose events: 3 [ 0.051010] ... event mask: 000000070000000f [ 0.052532] rcu: Hierarchical SRCU implementation. [ 0.054614] smp: Bringing up secondary CPUs ... [ 0.055577] x86: Booting SMP configuration: [ 0.056031] .... node #0, CPUs: #1 #2 #3 [ 0.084806] smp: Brought up 1 node, 4 CPUs [ 0.085909] smpboot: Max logical packages: 1 [ 0.086013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.122000] node 0 deferred pages initialised in 31ms [ 0.125336] devtmpfs: initialized [ 0.126215] x86/mm: Memory block size: 128MB [ 0.129064] gcov: version magic: 0x41383552 [ 0.131882] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.132071] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.133249] pinctrl core: initialized pinctrl subsystem [ 0.134174] [ 0.134570] ************************************************************* [ 0.135012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.136012] ** ** [ 0.137010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.138010] ** ** [ 0.139011] ** This means that this kernel is built to expose internal ** [ 0.140011] ** IOMMU data structures, which may compromise security on ** [ 0.141015] ** your system. ** [ 0.142015] ** ** [ 0.143008] ** If you see this message and you are not debugging the ** [ 0.144009] ** kernel, report this immediately to your vendor! ** [ 0.145010] ** ** [ 0.146009] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.147009] ************************************************************* [ 0.148737] NET: Registered protocol family 16 [ 0.149420] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.150060] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.151062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.152644] cpuidle: using governor menu [ 0.154814] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.155388] PCI: Using configuration type 1 for base access [ 0.156134] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.164284] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.165000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.167640] cryptd: max_cpu_qlen set to 1000 [ 0.175082] ACPI: Added _OSI(Module Device) [ 0.177015] ACPI: Added _OSI(Processor Device) [ 0.180015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.181012] ACPI: Added _OSI(Processor Aggregator Device) [ 0.185000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.190563] ACPI: Interpreter enabled [ 0.191059] ACPI: PM: (supports S0 S3 S4 S5) [ 0.193009] ACPI: Using IOAPIC for interrupt routing [ 0.202114] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.210393] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.230044] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.231048] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.232018] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.233080] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.236218] acpiphp: Slot [2] registered [ 0.237203] acpiphp: Slot [3] registered [ 0.238134] acpiphp: Slot [4] registered [ 0.239095] acpiphp: Slot [5] registered [ 0.240155] acpiphp: Slot [6] registered [ 0.241101] acpiphp: Slot [7] registered [ 0.242102] acpiphp: Slot [8] registered [ 0.243151] acpiphp: Slot [9] registered [ 0.244148] acpiphp: Slot [10] registered [ 0.245172] acpiphp: Slot [11] registered [ 0.246131] acpiphp: Slot [12] registered [ 0.247140] acpiphp: Slot [13] registered [ 0.248117] acpiphp: Slot [14] registered [ 0.249088] acpiphp: Slot [15] registered [ 0.250121] acpiphp: Slot [16] registered [ 0.251134] acpiphp: Slot [17] registered [ 0.252110] acpiphp: Slot [18] registered [ 0.253129] acpiphp: Slot [19] registered [ 0.254103] acpiphp: Slot [20] registered [ 0.255110] acpiphp: Slot [21] registered [ 0.256147] acpiphp: Slot [22] registered [ 0.257152] acpiphp: Slot [23] registered [ 0.258144] acpiphp: Slot [24] registered [ 0.259100] acpiphp: Slot [25] registered [ 0.261061] acpiphp: Slot [26] registered [ 0.262120] acpiphp: Slot [27] registered [ 0.263128] acpiphp: Slot [28] registered [ 0.265030] acpiphp: Slot [29] registered [ 0.266129] acpiphp: Slot [30] registered [ 0.267073] acpiphp: Slot [31] registered [ 0.268075] PCI host bridge to bus 0000:00 [ 0.269022] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.270024] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.271022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.272039] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.273020] pci_bus 0000:00: root bus resource [mem 0x180000000-0x1ffffffff window] [ 0.274037] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.275150] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.278020] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.281488] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.287629] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.292087] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.293027] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.294030] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.295031] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.297000] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.297000] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.307092] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.314108] pci 0000:00:01.3: quirk_piix4_acpi+0x0/0x1e0 took 16601 usecs [ 0.319640] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.336024] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.373026] pci 0000:00:02.0: reg 0x20: [mem 0xfebe4000-0xfebe7fff 64bit pref] [ 0.386024] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.399000] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.422019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.457017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.496018] pci 0000:00:05.0: reg 0x20: [mem 0xfebe8000-0xfebebfff 64bit pref] [ 0.514682] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.529027] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.538054] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.564016] pci 0000:00:06.0: reg 0x20: [mem 0xfebec000-0xfebeffff 64bit pref] [ 0.573206] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.579017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.591026] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.633000] pci 0000:00:07.0: reg 0x20: [mem 0xfebf0000-0xfebf3fff 64bit pref] [ 0.647710] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.658019] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.678025] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.701018] pci 0000:00:08.0: reg 0x20: [mem 0xfebf4000-0xfebf7fff 64bit pref] [ 0.715000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.723021] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.729021] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.745019] pci 0000:00:09.0: reg 0x20: [mem 0xfebf8000-0xfebfbfff 64bit pref] [ 0.754136] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.770015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.777017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.792017] pci 0000:00:0a.0: reg 0x20: [mem 0xfebfc000-0xfebfffff 64bit pref] [ 0.801000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.803443] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.805395] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.806000] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.807246] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.812041] iommu: Default domain type: Passthrough [ 0.814571] SCSI subsystem initialized [ 0.816149] ACPI: bus type USB registered [ 0.818131] usbcore: registered new interface driver usbfs [ 0.823114] usbcore: registered new interface driver hub [ 0.826092] usbcore: registered new device driver usb [ 0.828242] pps_core: LinuxPPS API ver. 1 registered [ 0.829010] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.830059] PTP clock support registered [ 0.834902] EDAC MC: Ver: 3.0.0 [ 0.839011] PCI: Using ACPI for IRQ routing [ 0.842819] NetLabel: Initializing [ 0.843012] NetLabel: domain hash size = 128 [ 0.844000] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.844000] NetLabel: unlabeled traffic allowed by default [ 0.846394] vgaarb: loaded [ 0.852183] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.856014] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.868000] clocksource: Switched to clocksource kvm-clock [ 1.119758] VFS: Disk quotas dquot_6.6.0 [ 1.121559] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.133222] *** VALIDATE ramfs *** [ 1.136703] *** VALIDATE hugetlbfs *** [ 1.143389] pnp: PnP ACPI init [ 1.146605] pnp: PnP ACPI: found 6 devices [ 1.188871] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.193895] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.196848] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.199410] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.212405] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.214832] pci_bus 0000:00: resource 8 [mem 0x180000000-0x1ffffffff window] [ 1.218133] NET: Registered protocol family 2 [ 1.221374] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.226899] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.230807] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.236703] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.240495] TCP: Hash tables configured (established 65536 bind 65536) [ 1.244507] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.247796] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.251806] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.268239] NET: Registered protocol family 1 [ 1.272877] RPC: Registered named UNIX socket transport module. [ 1.275922] RPC: Registered udp transport module. [ 1.277976] RPC: Registered tcp transport module. [ 1.279633] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.282520] NET: Registered protocol family 44 [ 1.284137] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.286782] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.289208] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.292095] PCI: CLS 0 bytes, default 64 [ 1.296687] Unpacking initramfs... [ 4.745293] debug: unmapping init [mem 0xffff935e3cc54000-0xffff935e3ffbffff] [ 4.757707] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 4.761761] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 4.769690] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 5.796554] Initialise system trusted keyrings [ 5.803854] Key type blacklist registered [ 5.806920] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 5.841730] zbud: loaded [ 5.850094] *** VALIDATE nfs *** [ 5.854777] *** VALIDATE nfs4 *** [ 5.861903] pstore: using deflate compression [ 5.882984] Platform Keyring initialized [ 6.173498] NET: Registered protocol family 38 [ 6.176157] Key type asymmetric registered [ 6.177655] Asymmetric key parser 'x509' registered [ 6.181179] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 6.184358] io scheduler mq-deadline registered [ 6.186797] io scheduler kyber registered [ 6.188525] io scheduler bfq registered [ 6.193945] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 6.196911] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 6.207806] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 6.211871] ACPI: Power Button [PWRF] [ 6.341986] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 6.514352] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 7.039495] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 7.300237] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 7.680967] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 7.748411] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 7.808064] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 7.813850] Non-volatile memory driver v1.3 [ 7.816336] Linux agpgart interface v0.103 [ 7.904224] virtio_blk virtio1: [vda] 133848 512-byte logical blocks (68.5 MB/65.4 MiB) [ 7.931408] vda: detected capacity change from 0 to 68530176 [ 7.966372] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 7.968641] vdb: detected capacity change from 0 to 1073741824 [ 8.010812] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 8.014376] vdc: detected capacity change from 0 to 2621440000 [ 8.032670] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 8.035747] vdd: detected capacity change from 0 to 2621440000 [ 8.075886] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 8.093043] vde: detected capacity change from 0 to 4294967296 [ 8.135809] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 8.149376] vdf: detected capacity change from 0 to 4294967296 [ 8.167169] libphy: Fixed MDIO Bus: probed [ 8.185450] usbcore: registered new interface driver usbserial_generic [ 8.188040] usbserial: USB Serial support registered for generic [ 8.190534] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 8.196897] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 8.198865] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 8.203585] mousedev: PS/2 mouse device common for all mice [ 8.209252] rtc_cmos 00:05: RTC can wake from S4 [ 8.212824] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 8.216251] rtc_cmos 00:05: registered as rtc0 [ 8.230196] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 8.252440] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 8.256173] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 8.258906] intel_pstate: CPU model not supported [ 8.277826] hid: raw HID events driver (C) Jiri Kosina [ 8.281951] usbcore: registered new interface driver usbhid [ 8.289370] usbhid: USB HID core driver [ 8.301172] drop_monitor: Initializing network drop monitor service [ 8.303547] Initializing XFRM netlink socket [ 8.305731] NET: Registered protocol family 10 [ 8.309537] Segment Routing with IPv6 [ 8.311039] NET: Registered protocol family 17 [ 8.313552] mpls_gso: MPLS GSO support [ 8.324232] RAS: Correctable Errors collector initialized. [ 8.326022] AVX version of gcm_enc/dec engaged. [ 8.332624] AES CTR mode by8 optimization enabled [ 8.551167] sched_clock: Marking stable (8551127611, 0)->(9977534762, -1426407151) [ 8.558281] registered taskstats version 1 [ 8.560454] Loading compiled-in X.509 certificates [ 8.562504] zswap: loaded using pool lzo/zbud [ 8.680432] Key type big_key registered [ 8.717668] Key type encrypted registered [ 8.720642] ima: No TPM chip found, activating TPM-bypass! [ 8.726621] ima: Allocated hash algorithm: sha1 [ 8.731454] ima: No architecture policies found [ 8.733320] evm: Initialising EVM extended attributes: [ 8.744154] evm: security.selinux [ 8.745420] evm: security.ima [ 8.748176] evm: security.capability [ 8.753581] evm: HMAC attrs: 0x1 [ 8.762306] rtc_cmos 00:05: setting system clock to 2025-11-17 00:05:51 UTC (1763337951) [ 8.784533] debug: unmapping init [mem 0xffffffffb2203000-0xffffffffb23fffff] [ 8.790667] debug: unmapping init [mem 0xffffffffb0f82000-0xffffffffb1258fff] [ 8.803111] Write protecting the kernel read-only data: 28672k [ 8.821552] debug: unmapping init [mem 0xffffffffaf603000-0xffffffffaf7fffff] [ 8.824328] debug: unmapping init [mem 0xffffffffaff14000-0xffffffffafffffff] [ 8.916826] 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) [ 8.942445] systemd[1]: Detected virtualization kvm. [ 8.945955] systemd[1]: Detected architecture x86-64. [ 8.948266] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 8.986314] systemd[1]: No hostname configured. [ 8.988030] systemd[1]: Set hostname to . [ 8.994610] random: systemd: uninitialized urandom read (16 bytes read) [ 8.999932] systemd[1]: Initializing machine ID from random generator. [ 9.315179] random: systemd: uninitialized urandom read (16 bytes read) [ 9.317675] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 9.321586] random: systemd: uninitialized urandom read (16 bytes read) [ 9.323756] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 9.334189] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. [ OK ] Reached target Timers. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Paths. Starting Apply Kernel Variables... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 10.677431] device-mapper: uevent: version 1.0.3 [ 10.679745] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 12.434809] virtio_net virtio0 ens2: renamed from eth0 [ 12.502737] random: fast init done [ 12.617194] scsi host0: ata_piix [ 12.726859] scsi host1: ata_piix [ 12.728445] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 12.730958] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 18.287337] random: crng init done [ 18.288756] random: 7 urandom warning(s) missed due to ratelimiting [ 19.496764] dracut-initqueue[591]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 21.218367] 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 Remote File Systems. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ 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... [ 23.650112] printk: systemd: 26 output lines suppressed due to ratelimiting [ 24.651980] SELinux: Disabled at runtime. [ 24.788786] 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) [ 24.796766] systemd[1]: Detected virtualization kvm. [ 24.799841] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 26.592118] systemd[1]: initrd-switch-root.service: Succeeded. [ 26.605980] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 26.623988] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 26.628972] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 26.632515] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 26.643329] systemd[1]: Starting Journal Service... Starting Journal Service... [ 26.658976] systemd[1]: Stopped target Switch Root. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Mounting Huge Pages File System... [ OK ] Listening on udev Kernel Socket. Mounting Kernel Debug File System... Mounting POSIX Message Queue File System... Starting Remount Root and Kernel File Systems... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Reached target rpc_pipefs.target. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Forward Password Requests to Wall Directory Watch. Activating swap /dev/disk/by-label/SWAP... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Process Core Dump Socket. [ 27.107514] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Apply Kernel Variables... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Created slice system-getty.slice. [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [ 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 ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ 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 udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 27.934453] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 28.983549] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 29.020288] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 29.733704] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 30.145733] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (7s / no limit) [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 34.991702] Key type dns_resolver registered [ *** ] A start job is running for Configur…-only root support (9s / no limit)[ 35.789262] NFS: Registering the id_resolver key type [ 35.791112] Key type id_resolver registered [ 35.792809] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ 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 ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ 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 irqbalance daemon. Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ 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 OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ 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. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg224-server login: [ 50.339018] hrtimer: interrupt took 5008972 ns [ 72.499120] spl: loading out-of-tree module taints kernel. [ 77.981573] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 88.239651] Key type ._llcrypt registered [ 88.241366] Key type .llcrypt registered [ 88.358219] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_hostid [ 104.903572] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing load_modules_local [ 106.111682] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 106.145493] alg: No test for adler32 (adler32-zlib) [ 107.684675] Lustre: Lustre: Build Version: 2.16.61_50_g1f7afa2 [ 108.567800] LNet: Added LNI 192.168.202.124@tcp [8/256/0/180] [ 110.311681] Key type lgssc registered [ 112.486158] Lustre: Echo OBD driver; http://www.lustre.org/ [ 121.910867] vdc: vdc1 vdc9 [ 130.614570] vde: vde1 vde9 [ 138.811084] vdf: vdf1 vdf9 [ 153.041498] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing load_modules_local [ 159.881047] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 161.177762] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 161.411682] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 161.466856] Lustre: lustre-MDT0000: new disk, initializing [ 162.027712] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 162.114688] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 166.168431] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 171.333719] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 177.299876] Lustre: lustre-OST0000: new disk, initializing [ 177.313838] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 177.321587] Lustre: Skipped 1 previous similar message [ 177.435409] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 182.938544] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 182.945603] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 183.097951] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 183.889792] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 194.203567] Lustre: lustre-OST0001: new disk, initializing [ 194.205880] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 194.307573] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 199.283221] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 202.509902] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 202.521592] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 202.715553] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 210.213222] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 213.951215] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 224.243967] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing check_logdir /tmp/testlogs/ [ 228.767342] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing yml_node [ 232.830676] Lustre: DEBUG MARKER: Client: 2.16.61.50 [ 234.999165] Lustre: DEBUG MARKER: MDS: 2.16.61.50 [ 237.437848] Lustre: DEBUG MARKER: OSS: 2.16.61.50 [ 238.994427] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Sun Nov 16 19:09:40 EST 2025 [ 253.777625] Lustre: DEBUG MARKER: excepting tests: 59 36 [ 255.622407] Lustre: DEBUG MARKER: === replay-single: start setup 19:09:56 (1763338196) === [ 259.183070] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing check_config_client /mnt/lustre [ 272.859487] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 275.690189] Lustre: 11006:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 278.730169] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 281.733800] Lustre: DEBUG MARKER: === replay-single: finish setup 19:10:23 (1763338223) === [ 283.224610] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 19:10:24 (1763338224) [ 286.130257] LustreError: 11486:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 286.953667] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 288.637080] Lustre: Failing over lustre-MDT0000 [ 288.786221] LustreError: 11632:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 288.869198] Lustre: server umount lustre-MDT0000 complete [ 304.607283] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338231/real 1763338231] req@ffff935d81def480 x1848993960217472/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338247 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 304.608120] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 304.634108] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 304.651699] 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 [ 310.753860] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338237/real 1763338237] req@ffff935d81deed80 x1848993960217728/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338253 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 310.774331] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 314.855527] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e488599c [ 314.875928] Lustre: MGC192.168.202.124@tcp: Connection restored to 0@lo (at 0@lo) [ 315.396965] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 316.255202] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338242/real 1763338242] req@ffff935e9887c700 x1848993960218112/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338258 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 316.292339] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 318.816752] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 320.019243] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 320.080473] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 320.351194] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338247/real 1763338247] req@ffff935e9887d500 x1848993960218624/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338263 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 320.361518] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 324.724540] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 325.949203] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 329.574883] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 332.760634] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 19:11:13 (1763338273) [ 334.359945] Lustre: Failing over lustre-OST0000 [ 334.434512] LustreError: 12870:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 334.442045] LustreError: 12870:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 334.479695] Lustre: server umount lustre-OST0000 complete [ 334.816044] 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 [ 334.826088] Lustre: Skipped 1 previous similar message [ 334.829812] LustreError: 12415: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. [ 334.843461] LustreError: 12415:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 335.396964] LustreError: 6568:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 339.939437] LustreError: 6568: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. [ 345.056904] LustreError: 6568: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. [ 345.066044] LustreError: 6568:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 350.176325] LustreError: 6568: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. [ 350.188063] LustreError: 6568:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 350.742421] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 351.877786] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 352.378604] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 352.384065] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 352.386431] Lustre: Skipped 1 previous similar message [ 355.843405] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 362.118606] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 363.700875] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 372.256695] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 19:11:53 (1763338313) [ 374.968408] LustreError: 14206:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 375.901575] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 378.296727] Lustre: Failing over lustre-MDT0000 [ 378.510866] LustreError: 14354:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 378.517851] LustreError: 14354:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 378.625305] Lustre: server umount lustre-MDT0000 complete [ 395.081488] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 395.345241] 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 [ 395.506068] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 397.418751] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338324/real 1763338324] req@ffff935eac4d7800 x1848993960245504/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338340 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 397.441037] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 398.575848] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 400.179964] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 400.185865] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 400.870202] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 405.524161] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:54 [ 408.031252] Lustre: 3319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338334/real 1763338334] req@ffff935eac4d5880 x1848993960246144/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338350 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 408.062273] Lustre: 3319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 410.648173] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:49 [ 415.769604] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:44 [ 420.893533] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:39 [ 431.129904] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:28 [ 431.144426] Lustre: Skipped 1 previous similar message [ 451.601403] Lustre: lustre-MDT0000: Denying connection for new client 49afb320-60cf-4422-be36-21e392d8be70 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:08 [ 451.614291] Lustre: Skipped 3 previous similar messages [ 460.003959] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 460.012933] Lustre: 14809:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client f62f6b4e-01e6-40eb-9449-733ca5062c6e@ [ 460.030499] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 460.068881] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 460.102279] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:65) [ 460.102524] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:65) [ 469.145884] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 19:13:30 (1763338410) [ 471.648841] LustreError: 15531:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 472.345242] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 474.018561] Lustre: Failing over lustre-MDT0000 [ 474.277882] LustreError: 15678:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 474.280086] LustreError: 15678:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 474.374297] Lustre: server umount lustre-MDT0000 complete [ 490.224192] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 490.454493] 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 [ 490.467646] Lustre: Skipped 2 previous similar messages [ 490.613269] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 493.536149] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338420/real 1763338420] req@ffff935e84c2aa00 x1848993960268672/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338436 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 493.569618] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 493.643112] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 495.445827] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 495.457241] Lustre: lustre-MDT0000: Denying connection for new client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 495.468600] Lustre: Skipped 1 previous similar message [ 495.589691] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 495.597771] Lustre: Skipped 1 previous similar message [ 555.000168] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 555.002848] Lustre: 16113:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 49afb320-60cf-4422-be36-21e392d8be70@ [ 555.024222] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 555.113751] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 555.171528] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:97) [ 555.172331] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:97) [ 568.063274] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 19:15:08 (1763338508) [ 571.633922] LustreError: 16835:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 572.625274] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 574.859557] Lustre: Failing over lustre-MDT0000 [ 575.114400] LustreError: 16983:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 575.117468] LustreError: 16983:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 575.251979] Lustre: server umount lustre-MDT0000 complete [ 592.203816] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 592.612796] 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 [ 592.626822] Lustre: Skipped 1 previous similar message [ 592.748768] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 593.089572] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 593.188695] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 593.232935] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:129) [ 593.238221] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:129) [ 593.704136] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338520/real 1763338520] req@ffff935eb34a8380 x1848993960291712/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338536 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 593.733271] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 596.735635] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 597.994262] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 597.998515] Lustre: Skipped 1 previous similar message [ 603.293879] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 604.657769] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 611.699135] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 19:15:52 (1763338552) [ 614.039409] LustreError: 18263:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 614.740505] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 616.245333] Lustre: Failing over lustre-MDT0000 [ 616.430529] LustreError: 18409:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 616.435032] LustreError: 18409:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 616.499314] Lustre: server umount lustre-MDT0000 complete [ 632.301090] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 632.602627] 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 [ 632.618245] Lustre: Skipped 1 previous similar message [ 632.850583] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 633.926367] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 634.032875] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 634.059093] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 634.059142] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:161) [ 636.027276] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 637.922882] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 637.933032] Lustre: Skipped 1 previous similar message [ 642.825895] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 644.198728] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 651.658496] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 19:16:32 (1763338592) [ 654.293597] LustreError: 19662:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 655.093921] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 656.868941] Lustre: Failing over lustre-MDT0000 [ 657.130362] LustreError: 19807:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 657.133224] LustreError: 19807:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 657.215656] Lustre: server umount lustre-MDT0000 complete [ 674.536910] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338601/real 1763338601] req@ffff935e8662e300 x1848993960318336/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338617 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 674.569932] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 674.582313] 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 [ 674.687295] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 674.942524] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.24@tcp (not set up) [ 675.264253] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 675.267333] Lustre: Skipped 1 previous similar message [ 675.388465] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 676.366349] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 676.588410] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 676.668275] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:193) [ 676.673327] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:163 to 0x240000400:193) [ 679.203690] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 679.211306] Lustre: Skipped 1 previous similar message [ 680.064253] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 687.878961] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 689.794235] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 698.201296] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 19:17:19 (1763338639) [ 701.635803] LustreError: 21080:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 702.538184] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 704.553490] Lustre: Failing over lustre-MDT0000 [ 704.769883] LustreError: 21225:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 704.773919] LustreError: 21225:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 704.885563] Lustre: server umount lustre-MDT0000 complete [ 720.351381] 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 [ 720.359899] Lustre: Skipped 2 previous similar messages [ 720.974951] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 721.403692] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 725.009552] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 731.172675] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 731.409524] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 731.490230] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:225) [ 731.490690] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:225) [ 735.047769] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 736.537778] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 743.374427] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 19:18:04 (1763338684) [ 745.671498] LustreError: 22493:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 746.391302] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 748.152885] Lustre: Failing over lustre-MDT0000 [ 748.549501] Lustre: server umount lustre-MDT0000 complete [ 765.876965] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 766.308609] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 766.666511] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 767.260178] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:257) [ 767.261161] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:257) [ 769.838106] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 771.559921] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 771.567541] Lustre: Skipped 3 previous similar messages [ 776.079357] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 778.064567] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 786.702860] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 19:18:47 (1763338727) [ 787.776791] Lustre: *** cfs_fail_loc=13b, val=315*** [ 787.778535] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 787.780683] LustreError: 23053:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935eab71d500 x1848993942454400/t38654705666(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:7/0 lens 392/456 e 0 to 0 dl 1763338747 ref 1 fl Interpret:/600/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 792.207208] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 794.006265] Lustre: Failing over lustre-MDT0000 [ 794.171907] LustreError: 24116:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 794.174856] LustreError: 24116:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 794.307066] Lustre: server umount lustre-MDT0000 complete [ 812.508988] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763338739/real 1763338739] req@ffff935eac7c7480 x1848993960362752/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763338755 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 812.512726] 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 [ 812.523102] LustreError: 24530: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. [ 812.527356] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 20 previous similar messages [ 812.553627] Lustre: Skipped 3 previous similar messages [ 812.832186] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 812.835982] Lustre: Skipped 2 previous similar messages [ 812.893354] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 815.990437] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 820.377278] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 820.381701] Lustre: Skipped 1 previous similar message [ 820.459304] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 820.466739] Lustre: Skipped 1 previous similar message [ 820.513136] Lustre: 24533:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935ec1e29180 x1848993942454400/t38654705666(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:40/0 lens 392/456 e 0 to 0 dl 1763338780 ref 1 fl Interpret:/602/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 820.518593] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:289) [ 820.521747] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:289) [ 823.595751] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 825.013317] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 832.329700] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 19:19:33 (1763338773) [ 834.422453] LustreError: 25396:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 834.426301] LustreError: 25396:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 835.152236] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 836.436104] Lustre: Failing over lustre-MDT0000 [ 836.637855] Lustre: server umount lustre-MDT0000 complete [ 852.841452] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 852.848587] LustreError: Skipped 1 previous similar message [ 853.374820] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 856.531209] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 856.814089] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:321) [ 856.827240] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:321) [ 863.111865] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 864.318447] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 869.886386] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 19:20:11 (1763338811) [ 872.764757] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 873.561659] Lustre: *** cfs_fail_loc=114, val=0*** [ 875.814801] Lustre: Failing over lustre-MDT0000 [ 876.033765] Lustre: server umount lustre-MDT0000 complete [ 892.460938] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 892.569717] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:353) [ 892.573059] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:353) [ 895.921325] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 902.082790] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 903.499805] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 911.866935] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 19:20:52 (1763338852) [ 915.201306] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 915.963229] Lustre: *** cfs_fail_loc=128, val=0*** [ 918.038346] Lustre: Failing over lustre-MDT0000 [ 918.321891] Lustre: server umount lustre-MDT0000 complete [ 935.731427] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 938.708456] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:385) [ 938.708552] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:385) [ 939.359675] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 941.036107] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 941.040558] Lustre: Skipped 7 previous similar messages [ 945.934930] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 947.275939] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 955.708272] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 19:21:36 (1763338896) [ 959.028463] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 961.145421] Lustre: Failing over lustre-MDT0000 [ 961.352240] LustreError: 29991:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 961.360653] LustreError: 29991:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 961.470219] Lustre: server umount lustre-MDT0000 complete [ 977.887741] 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 [ 977.895458] Lustre: Skipped 7 previous similar messages [ 979.484324] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 979.487510] Lustre: Skipped 3 previous similar messages [ 979.817016] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 979.823730] Lustre: Skipped 3 previous similar messages [ 979.856132] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:391 to 0x240000400:417) [ 979.859194] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:391 to 0x280000400:417) [ 981.557674] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 988.076573] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 989.471831] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 996.707337] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 19:22:18 (1763338938) [ 1000.100548] LustreError: 31264:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1000.105080] LustreError: 31264:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 1001.089240] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1003.295508] Lustre: Failing over lustre-MDT0000 [ 1005.101668] LustreError: 30398:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1005.123291] LustreError: 30398:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 1005.609313] Lustre: server umount lustre-MDT0000 complete [ 1022.137395] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1022.143922] LustreError: Skipped 3 previous similar messages [ 1022.732786] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1022.736675] Lustre: Skipped 1 previous similar message [ 1025.693199] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:423 to 0x240000400:449) [ 1025.695338] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:423 to 0x280000400:449) [ 1026.292124] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1032.801911] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1034.300183] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1043.016612] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 19:23:03 (1763338983) [ 1047.110834] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1058.039077] Lustre: Failing over lustre-MDT0000 [ 1058.277558] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1058.290147] Lustre: Skipped 2 previous similar messages [ 1058.426852] Lustre: server umount lustre-MDT0000 complete [ 1076.786537] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.24@tcp (not set up) [ 1076.978360] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1076.981279] Lustre: Skipped 5 previous similar messages [ 1081.472585] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1083.984791] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:577) [ 1083.990052] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:577) [ 1088.854856] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1090.143520] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1110.868936] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 19:24:12 (1763339052) [ 1114.566452] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1116.548407] Lustre: Failing over lustre-MDT0000 [ 1116.929218] Lustre: server umount lustre-MDT0000 complete [ 1136.288493] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763339062/real 1763339062] req@ffff935e82e54000 x1848993960523008/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763339078 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1136.308130] Lustre: 3317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 37 previous similar messages [ 1138.914551] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1144.503490] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:609) [ 1144.509254] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:609) [ 1147.186427] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1148.419160] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1157.951738] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 19:24:59 (1763339099) [ 1161.805188] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1163.331877] Lustre: Failing over lustre-MDT0000 [ 1163.596322] Lustre: server umount lustre-MDT0000 complete [ 1180.753642] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1180.756830] Lustre: Skipped 2 previous similar messages [ 1181.207154] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:641) [ 1181.210652] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:641) [ 1184.181883] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1190.580943] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1191.948867] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1199.272447] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 19:25:40 (1763339140) [ 1202.503796] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1204.212629] Lustre: Failing over lustre-MDT0000 [ 1204.503734] Lustre: server umount lustre-MDT0000 complete [ 1233.640675] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:673) [ 1233.642246] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:673) [ 1237.591105] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1245.495495] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1246.950906] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1246.958458] Lustre: Skipped 11 previous similar messages [ 1247.208949] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1255.901729] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 19:26:36 (1763339196) [ 1259.197160] LustreError: 38436:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1259.203538] LustreError: 38436:0:(osd_handler.c:720:osd_ro()) Skipped 4 previous similar messages [ 1260.207487] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1262.393175] Lustre: Failing over lustre-MDT0000 [ 1262.564710] 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 [ 1262.573301] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1262.581681] Lustre: Skipped 11 previous similar messages [ 1262.588378] Lustre: Skipped 1 previous similar message [ 1262.692826] LustreError: 38583:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 1262.694936] LustreError: 38583:0:(obd_class.h:479:obd_check_dev()) Skipped 35 previous similar messages [ 1262.827411] Lustre: server umount lustre-MDT0000 complete [ 1279.488630] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1279.493212] LustreError: Skipped 4 previous similar messages [ 1280.534467] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1280.540680] Lustre: Skipped 5 previous similar messages [ 1280.723403] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1280.728136] Lustre: Skipped 5 previous similar messages [ 1280.764731] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:705) [ 1280.765409] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:705) [ 1282.964413] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1289.948569] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1291.432460] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1299.014270] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 19:27:20 (1763339240) [ 1303.105718] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1305.027485] Lustre: Failing over lustre-MDT0000 [ 1305.357640] Lustre: server umount lustre-MDT0000 complete [ 1328.602981] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1331.876189] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:737) [ 1331.880392] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:737) [ 1334.981835] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1336.501766] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1343.636250] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 19:28:04 (1763339284) [ 1347.954817] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1350.036785] Lustre: Failing over lustre-MDT0000 [ 1350.118613] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1350.120765] Lustre: Skipped 1 previous similar message [ 1350.445167] Lustre: server umount lustre-MDT0000 complete [ 1372.645859] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1378.017284] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:769) [ 1378.018745] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:769) [ 1381.459277] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1383.360491] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1391.724498] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 19:28:52 (1763339332) [ 1395.305897] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1397.360914] Lustre: Failing over lustre-MDT0000 [ 1397.674873] Lustre: server umount lustre-MDT0000 complete [ 1418.126865] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1424.119066] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:801) [ 1424.120949] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:801) [ 1427.381588] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1428.991894] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1437.560915] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 19:29:38 (1763339378) [ 1441.235457] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1443.783685] Lustre: Failing over lustre-MDT0000 [ 1444.284063] Lustre: server umount lustre-MDT0000 complete [ 1471.971490] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e4895bca [ 1472.547760] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1472.550338] Lustre: Skipped 5 previous similar messages [ 1476.266435] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1485.584053] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:833) [ 1485.584434] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:833) [ 1489.204201] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1490.672890] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1499.186882] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 19:30:40 (1763339440) [ 1503.242620] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1505.408396] Lustre: Failing over lustre-MDT0000 [ 1505.684198] Lustre: server umount lustre-MDT0000 complete [ 1527.083193] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1532.600623] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:835 to 0x240000400:865) [ 1532.618155] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:865) [ 1535.912707] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1537.493846] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1546.471908] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 19:31:27 (1763339487) [ 1549.930739] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1551.814938] Lustre: Failing over lustre-MDT0000 [ 1552.238512] Lustre: server umount lustre-MDT0000 complete [ 1569.505681] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:897) [ 1569.506062] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:867 to 0x240000400:897) [ 1572.440379] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1578.293525] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1579.932853] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1588.968455] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 19:32:09 (1763339529) [ 1592.440122] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1594.226071] Lustre: Failing over lustre-MDT0000 [ 1594.514333] Lustre: server umount lustre-MDT0000 complete [ 1612.209108] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1612.212193] Lustre: Skipped 10 previous similar messages [ 1615.858757] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1621.767500] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:929) [ 1621.771127] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:929) [ 1625.146947] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1626.877735] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1634.150058] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 19:32:55 (1763339575) [ 1637.534390] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1639.256440] Lustre: Failing over lustre-MDT0000 [ 1639.641641] Lustre: server umount lustre-MDT0000 complete [ 1657.649075] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:931 to 0x240000400:961) [ 1657.653304] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:961) [ 1657.887135] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763339584/real 1763339584] req@ffff935eac4d4380 x1848993960685824/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763339600 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1657.905583] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 63 previous similar messages [ 1660.938685] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1667.844848] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1669.555775] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1677.682990] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 19:33:38 (1763339618) [ 1681.493644] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1683.172774] Lustre: Failing over lustre-MDT0000 [ 1683.569594] Lustre: server umount lustre-MDT0000 complete [ 1703.676589] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:963 to 0x240000400:993) [ 1703.677305] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:993) [ 1706.311255] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1714.131730] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1715.762490] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1723.867738] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 19:34:25 (1763339665) [ 1727.718430] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1730.102168] Lustre: Failing over lustre-MDT0000 [ 1730.534155] Lustre: server umount lustre-MDT0000 complete [ 1758.701728] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e48978e2 [ 1760.054006] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:995 to 0x280000400:1025) [ 1760.059264] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:995 to 0x240000400:1025) [ 1762.894863] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1769.992934] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1771.973001] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1773.351819] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1773.359532] Lustre: Skipped 23 previous similar messages [ 1780.609831] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 19:35:21 (1763339721) [ 1783.246379] LustreError: 54123:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1783.250670] LustreError: 54123:0:(osd_handler.c:720:osd_ro()) Skipped 10 previous similar messages [ 1784.052110] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1786.065471] Lustre: Failing over lustre-MDT0000 [ 1786.326511] LustreError: 54269:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 1786.334327] LustreError: 54269:0:(obd_class.h:479:obd_check_dev()) Skipped 65 previous similar messages [ 1786.402779] Lustre: server umount lustre-MDT0000 complete [ 1804.024308] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1804.047569] LustreError: Skipped 10 previous similar messages [ 1804.256275] 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 [ 1804.274456] Lustre: Skipped 20 previous similar messages [ 1804.299419] LustreError: 54677: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. [ 1805.817406] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1805.834076] Lustre: Skipped 10 previous similar messages [ 1806.161806] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1806.176584] Lustre: Skipped 10 previous similar messages [ 1806.274465] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1057) [ 1806.287479] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1057) [ 1810.551835] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1818.401785] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1820.110693] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1828.080431] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 19:36:09 (1763339769) [ 1832.280109] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1834.193990] Lustre: Failing over lustre-MDT0000 [ 1834.576795] Lustre: server umount lustre-MDT0000 complete [ 1862.180803] LustreError: 56096:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1862.195523] LustreError: 56096:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 1864.442703] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1089) [ 1864.446573] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1059 to 0x280000400:1089) [ 1867.361909] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1876.070982] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1878.607115] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1888.602656] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 19:37:09 (1763339829) [ 1892.947911] Lustre: 56959:0:(genops.c:1791:obd_export_evict_by_uuid()) lustre-MDT0000: evicting e6eb6064-a37e-4bc3-b753-dbe720727416 at adminstrative request [ 1899.569830] Lustre: Failing over lustre-MDT0000 [ 1900.003307] Lustre: server umount lustre-MDT0000 complete [ 1918.930666] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 1918.934025] Lustre: Skipped 1 previous similar message [ 1919.737358] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1091 to 0x240000400:1121) [ 1919.738771] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1059 to 0x280000400:1121) [ 1923.211800] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1930.509213] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1932.456266] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1937.330884] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1949.834907] Lustre: DEBUG MARKER: before 6144, after 6144 [ 1956.322559] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 19:38:17 (1763339897) [ 1957.407708] Lustre: 58719:0:(genops.c:1791:obd_export_evict_by_uuid()) lustre-MDT0000: evicting e6eb6064-a37e-4bc3-b753-dbe720727416 at adminstrative request [ 1968.449401] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 19:38:28 (1763339908) [ 1972.963709] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1975.266161] Lustre: Failing over lustre-MDT0000 [ 1975.704922] Lustre: server umount lustre-MDT0000 complete [ 1996.391234] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1996.405204] Lustre: Skipped 9 previous similar messages [ 2001.828591] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2002.762975] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1124 to 0x280000400:1153) [ 2002.763324] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1123 to 0x240000400:1153) [ 2009.747338] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2011.284594] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2020.700054] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 19:39:21 (1763339961) [ 2025.731349] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2028.427661] Lustre: Failing over lustre-MDT0000 [ 2028.850634] Lustre: server umount lustre-MDT0000 complete [ 2048.714593] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1155 to 0x240000400:1185) [ 2048.718784] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1155 to 0x280000400:1185) [ 2052.226370] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2059.332362] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2060.936584] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2069.550591] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 19:40:10 (1763340010) [ 2073.561396] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2075.241815] Lustre: Failing over lustre-MDT0000 [ 2075.506121] Lustre: server umount lustre-MDT0000 complete [ 2094.829254] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1187 to 0x240000400:1217) [ 2094.830503] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1187 to 0x280000400:1217) [ 2097.747779] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2104.233252] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2105.642544] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2115.003144] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 19:40:55 (1763340055) [ 2118.852798] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2120.600084] Lustre: Failing over lustre-MDT0000 [ 2120.886066] Lustre: server umount lustre-MDT0000 complete [ 2140.685150] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2140.869372] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1219 to 0x240000400:1249) [ 2140.869742] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1249) [ 2146.741516] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2148.320975] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2156.295939] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 19:41:37 (1763340097) [ 2159.606417] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2161.218864] Lustre: Failing over lustre-MDT0000 [ 2161.442531] Lustre: server umount lustre-MDT0000 complete [ 2181.830929] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1219 to 0x240000400:1281) [ 2181.833111] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1251 to 0x280000400:1281) [ 2182.829284] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2189.786305] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2191.414901] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2199.436813] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 19:42:20 (1763340140) [ 2202.768914] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2204.953914] Lustre: Failing over lustre-MDT0000 [ 2205.384492] Lustre: server umount lustre-MDT0000 complete [ 2222.615414] LustreError: 66670:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2223.054261] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2223.064043] Lustre: Skipped 11 previous similar messages [ 2224.305899] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1283 to 0x240000400:1313) [ 2224.308732] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1283 to 0x280000400:1313) [ 2226.630836] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2233.563133] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2234.844730] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2242.359693] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 19:43:03 (1763340183) [ 2245.794661] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2247.702307] Lustre: Failing over lustre-MDT0000 [ 2248.120814] Lustre: server umount lustre-MDT0000 complete [ 2265.014464] Lustre: 3319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763340191/real 1763340191] req@ffff935d81deed80 x1848993960869888/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763340207 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2265.051944] Lustre: 3319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 82 previous similar messages [ 2278.364378] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2289.347847] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1315 to 0x280000400:1345) [ 2289.347970] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1315 to 0x240000400:1345) [ 2292.931409] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2294.363228] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2301.772872] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 19:44:03 (1763340243) [ 2305.543923] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2307.741160] Lustre: Failing over lustre-MDT0000 [ 2308.139396] Lustre: server umount lustre-MDT0000 complete [ 2327.738725] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1347 to 0x240000400:1377) [ 2327.743174] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1347 to 0x280000400:1377) [ 2331.283633] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2338.405124] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2339.997200] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2348.291863] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 19:44:49 (1763340289) [ 2352.046895] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2353.959098] Lustre: Failing over lustre-MDT0000 [ 2354.292597] Lustre: server umount lustre-MDT0000 complete [ 2372.359461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1379 to 0x240000400:1409) [ 2372.362777] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1379 to 0x280000400:1409) [ 2376.386743] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2377.185586] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2377.190039] Lustre: Skipped 23 previous similar messages [ 2383.012789] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2384.515908] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2391.990819] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 19:45:33 (1763340333) [ 2395.066534] LustreError: 71822:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2395.070659] LustreError: 71822:0:(osd_handler.c:720:osd_ro()) Skipped 10 previous similar messages [ 2396.045647] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2398.030659] Lustre: Failing over lustre-MDT0000 [ 2398.248804] LustreError: 71967:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 2398.253243] LustreError: 71967:0:(obd_class.h:479:obd_check_dev()) Skipped 71 previous similar messages [ 2398.372443] Lustre: server umount lustre-MDT0000 complete [ 2415.842466] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2415.847223] LustreError: Skipped 11 previous similar messages [ 2416.145286] 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 [ 2416.158781] Lustre: Skipped 23 previous similar messages [ 2418.204273] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2418.206991] Lustre: Skipped 11 previous similar messages [ 2418.361269] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2418.372553] Lustre: Skipped 11 previous similar messages [ 2418.413821] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1411 to 0x280000400:1441) [ 2418.414555] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1411 to 0x240000400:1441) [ 2420.386264] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2427.179991] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2428.857805] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2436.939671] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 19:46:17 (1763340377) [ 2440.691029] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2442.415808] Lustre: Failing over lustre-MDT0000 [ 2442.826723] Lustre: server umount lustre-MDT0000 complete [ 2459.185501] LustreError: 73790:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2461.013679] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1443 to 0x240000400:1473) [ 2461.017018] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1443 to 0x280000400:1473) [ 2463.130669] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2469.847635] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2471.914787] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2480.479785] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 19:47:01 (1763340421) [ 2481.421610] Lustre: 74560:0:(genops.c:1791:obd_export_evict_by_uuid()) lustre-MDT0000: evicting e6eb6064-a37e-4bc3-b753-dbe720727416 at adminstrative request [ 2491.201833] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 19:47:12 (1763340432) [ 2493.933291] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2495.649475] Lustre: Failing over lustre-MDT0000 [ 2496.015916] Lustre: server umount lustre-MDT0000 complete [ 2503.613205] Lustre: lustre-MDT0000: Aborting client recovery [ 2503.616728] LustreError: 75423:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2503.630332] Lustre: 75468:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2503.636327] Lustre: 75468:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 2503.647573] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2503.703358] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 2503.789295] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1479 to 0x240000400:1505) [ 2503.789582] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1480 to 0x280000400:1505) [ 2507.429599] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2519.364053] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 19:47:40 (1763340460) [ 2523.062830] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2524.997334] Lustre: Failing over lustre-MDT0000 [ 2525.457592] Lustre: server umount lustre-MDT0000 complete [ 2535.378404] Lustre: *** cfs_fail_loc=1311, val=0*** [ 2535.412159] Lustre: lustre-MDT0000: Aborting client recovery [ 2535.417825] LustreError: 76725:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2535.422664] Lustre: 76772:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2535.439052] Lustre: 76772:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 2535.447287] Lustre: 76772:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 2535.455872] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2535.572713] Lustre: lustre-MDT0000-osd: cancel update llog [0x200015bc0:0x1:0x0] [ 2535.860354] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1516 to 0x280000400:1537) [ 2535.880063] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1516 to 0x240000400:1537) [ 2540.089310] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2545.352329] Lustre: *** cfs_fail_loc=1311, val=0*** [ 2551.465857] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 19:48:12 (1763340492) [ 2555.240890] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2557.048129] Lustre: Failing over lustre-MDT0000 [ 2557.397466] Lustre: server umount lustre-MDT0000 complete [ 2565.134917] Lustre: lustre-MDT0000: Aborting client recovery [ 2565.137853] LustreError: 78040:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2565.143874] Lustre: 78086:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2565.148247] Lustre: 78086:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 2565.153541] Lustre: 78086:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 2565.159621] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2565.198796] Lustre: lustre-MDT0000-osd: cancel update llog [0x200016778:0x1:0x0] [ 2565.311937] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1544 to 0x280000400:1569) [ 2565.319094] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1569) [ 2569.238188] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2580.969695] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 19:48:41 (1763340521) [ 2582.081792] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 2582.091060] LustreError: 78047:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935e86338000 x1848993943417088/t201863462916(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:285/0 lens 512/456 e 0 to 0 dl 1763340535 ref 1 fl Interpret:/200/0 rc 0/0 job:'rm.0' uid:0 gid:0 projid:4294967295 [ 2585.911911] Lustre: Failing over lustre-MDT0000 [ 2586.384572] Lustre: server umount lustre-MDT0000 complete [ 2594.694623] Lustre: lustre-MDT0000: Aborting client recovery [ 2594.697276] LustreError: 79173:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2594.716135] Lustre: 79220:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2594.722461] Lustre: 79220:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 2594.737591] Lustre: 79220:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 2594.747960] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2594.824849] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017330:0x1:0x0] [ 2595.008077] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1571 to 0x240000400:1601) [ 2595.011804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1544 to 0x280000400:1601) [ 2598.995078] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2609.938476] Lustre: DEBUG MARKER: SKIP: replay-single test_36 skipping ALWAYS excluded test 36 [ 2611.455987] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 19:49:12 (1763340552) [ 2615.411106] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2618.250633] Lustre: Failing over lustre-MDT0000 [ 2618.568445] Lustre: server umount lustre-MDT0000 complete [ 2628.249295] Lustre: lustre-MDT0000: Aborting client recovery [ 2628.250702] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2628.256557] LustreError: 80573:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2628.261936] Lustre: Skipped 22 previous similar messages [ 2628.262126] Lustre: 80620:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2628.262132] Lustre: 80620:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 2628.275230] Lustre: 80620:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 2628.280164] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2628.342595] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017b00:0x1:0x0] [ 2628.568908] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1571 to 0x240000400:1633) [ 2628.570787] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1544 to 0x280000400:1633) [ 2633.701490] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2648.476428] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 19:49:49 (1763340589) [ 2678.646633] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2680.350346] Lustre: Failing over lustre-MDT0000 [ 2680.762434] Lustre: server umount lustre-MDT0000 complete [ 2699.986058] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2034 to 0x240000400:2049) [ 2699.987113] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2034 to 0x280000400:2049) [ 2701.566869] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2708.050383] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2709.512265] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2728.831552] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 19:51:10 (1763340670) [ 2749.479184] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2759.734138] Lustre: Failing over lustre-MDT0000 [ 2760.014119] Lustre: server umount lustre-MDT0000 complete [ 2780.544145] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2783.260621] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2450 to 0x280000400:2465) [ 2783.264092] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2450 to 0x240000400:2465) [ 2786.675671] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2787.908050] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2808.631319] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 19:52:29 (1763340749) [ 2810.773370] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 2811.733473] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 2811.743529] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 2817.649631] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 19:52:38 (1763340758) [ 2840.583900] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 2852.570219] Lustre: Failing over lustre-OST0000 [ 2852.693377] Lustre: server umount lustre-OST0000 complete [ 2854.380234] LustreError: 14020: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. [ 2869.592781] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2869.598545] Lustre: Skipped 12 previous similar messages [ 2875.107871] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2933.027267] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 19:54:34 (1763340874) [ 2936.646893] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2939.413828] Lustre: Failing over lustre-MDT0000 [ 2939.820189] Lustre: server umount lustre-MDT0000 complete [ 2957.792450] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763340884/real 1763340884] req@ffff935eaacb0e00 x1848993961497216/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763340900 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2957.825511] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 58 previous similar messages [ 2968.034672] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e48e08fb [ 2972.150623] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2982.543460] Lustre: *** cfs_fail_loc=204, val=2147483648*** [ 2982.546399] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2881) [ 2982.884137] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2982.897475] Lustre: Skipped 22 previous similar messages [ 2987.685599] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2989.317882] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2998.751371] LustreError: 88091:0:(osp_precreate.c:969:osp_precreate_cleanup_orphans()) lustre-OST0000-osc-MDT0000: cannot cleanup orphans: rc = -11 [ 2998.752793] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 2999.780777] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2913) [ 3008.243860] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 19:55:49 (1763340949) [ 3013.692568] LustreError: 88628:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3018.719181] LustreError: 88628:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3018.725649] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3018.787327] LustreError: 12415:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 waking [ 3020.713807] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3025.887282] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3025.899995] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3027.584222] LustreError: 88628:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3033.055716] LustreError: 88628:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3033.059268] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3034.774863] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3040.223143] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3041.800126] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3046.883508] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3046.898846] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3046.913342] Lustre: Skipped 1 previous similar message [ 3055.920199] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3055.935804] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 1 previous similar message [ 3061.216739] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3061.225397] LustreError: 88068:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 1 previous similar message [ 3068.383292] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3068.390300] Lustre: Skipped 2 previous similar messages [ 3076.945528] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_race id 701 sleeping [ 3076.948340] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 2 previous similar messages [ 3082.207167] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3082.221799] LustreError: 88070:0:(ldlm_lib.c:1165:target_handle_connect()) Skipped 2 previous similar messages [ 3089.969844] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 19:57:10 (1763341030) [ 3091.571045] LustreError: 88628:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3101.718568] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3105.757096] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3106.773551] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3111.964282] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3117.075557] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3117.093511] Lustre: Skipped 1 previous similar message [ 3127.316130] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3127.322044] Lustre: Skipped 1 previous similar message [ 3131.607140] LustreError: 88628:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3131.612376] Lustre: 88628:0:(service.c:2560:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff935eaacb7100 x1848993946051840/t0(0) o38->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:0/0 lens 520/416 e 0 to 0 dl 1763341054 ref 1 fl Complete:H/200/0 rc 0/0 job:'lctl.0' uid:0 gid:0 projid:4294967295 [ 3132.441328] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3132.445165] Lustre: Skipped 3 previous similar messages [ 3132.447145] LustreError: 90402:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3157.015617] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3172.503157] LustreError: 90402:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3172.516913] Lustre: 90402:0:(service.c:2560:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff935eaacb1880 x1848993946055168/t0(0) o38->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:0/0 lens 520/416 e 0 to 0 dl 1763341095 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3177.494629] LustreError: 88068:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3202.088286] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3202.100583] Lustre: Skipped 4 previous similar messages [ 3217.568489] LustreError: 88068:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3217.571848] Lustre: 88068:0:(service.c:2560:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff935d81def800 x1848993946057344/t0(0) o38->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:0/0 lens 520/416 e 0 to 0 dl 1763341140 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3222.549328] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3222.557794] Lustre: Skipped 1 previous similar message [ 3222.560134] LustreError: 88068:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3262.575259] LustreError: 88068:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3262.589395] Lustre: 88068:0:(service.c:2560:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff935e841e5880 x1848993946059520/t0(0) o38->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:0/0 lens 520/416 e 0 to 0 dl 1763341185 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3267.605390] LustreError: 88070:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3293.208198] Lustre: lustre-MDT0000: Export ffff935eb40ed800 already connecting from 192.168.202.24@tcp [ 3293.221716] Lustre: Skipped 9 previous similar messages [ 3307.607163] LustreError: 88070:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3307.614955] Lustre: 88070:0:(service.c:2560:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff935e84c2b100 x1848993946061696/t0(0) o38->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:0/0 lens 520/416 e 0 to 0 dl 1763341230 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3308.564915] LustreError: 88069:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3316.176096] LustreError: 88069:0:(ldlm_lib.c:1418:target_handle_connect()) cfs_fail_timeout interrupted [ 3320.598758] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 20:01:01 (1763341261) [ 3323.148914] LustreError: 91861:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3323.156103] LustreError: 91861:0:(osd_handler.c:720:osd_ro()) Skipped 9 previous similar messages [ 3324.108935] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3328.445456] Lustre: Failing over lustre-MDT0000 [ 3328.741851] LustreError: 92059:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 3328.750886] LustreError: 92059:0:(obd_class.h:479:obd_check_dev()) Skipped 61 previous similar messages [ 3328.880986] Lustre: server umount lustre-MDT0000 complete [ 3335.620806] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3335.628262] LustreError: Skipped 9 previous similar messages [ 3335.939736] 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 [ 3335.940366] Lustre: *** cfs_fail_loc=712, val=0*** [ 3335.952588] Lustre: Skipped 22 previous similar messages [ 3335.965488] LustreError: 33811:0:(service.c:1389:ptlrpc_check_req()) @@@ Invalid replay without recovery req@ffff935eb39aaa00 x1848993961578752/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 [ 3336.167696] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3336.170786] Lustre: Skipped 6 previous similar messages [ 3336.173183] Lustre: lustre-MDT0000: Aborting client recovery [ 3336.175439] LustreError: 92481:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3336.182647] Lustre: 92526:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3336.187806] Lustre: 92526:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 3336.192809] Lustre: 92526:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e6eb6064-a37e-4bc3-b753-dbe720727416@ [ 3336.200314] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3336.252830] Lustre: lustre-MDT0000-osd: cancel update llog [0x2000182d0:0x1:0x0] [ 3336.371735] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2913) [ 3336.380698] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2945) [ 3339.294379] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3345.688902] Lustre: Failing over lustre-MDT0000 [ 3346.042125] Lustre: server umount lustre-MDT0000 complete [ 3364.885150] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3364.892726] Lustre: Skipped 5 previous similar messages [ 3364.981229] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3364.984130] Lustre: Skipped 5 previous similar messages [ 3365.024760] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2945) [ 3365.024878] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2977) [ 3366.520358] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3372.900385] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3374.366193] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3381.798173] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 20:02:03 (1763341323) [ 3381.892717] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 3381.896801] Lustre: Skipped 2 previous similar messages [ 3387.771262] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 20:02:09 (1763341329) [ 3388.597317] Lustre: *** cfs_fail_loc=122, val=2147483648*** [ 3388.599484] LustreError: 93374:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935ebf91f480 x1848993946116736/t0(0) o700->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:337/0 lens 264/248 e 0 to 0 dl 1763341342 ref 1 fl Interpret:/200/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:4294967295 [ 3407.805423] Lustre: Failing over lustre-MDT0000 [ 3408.156652] Lustre: server umount lustre-MDT0000 complete [ 3425.421831] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2979 to 0x240000400:3009) [ 3425.426408] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2947 to 0x280000400:2977) [ 3427.456735] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3433.855679] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3435.634878] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3444.894660] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 20:03:05 (1763341385) [ 3447.265762] Lustre: Failing over lustre-OST0000 [ 3447.346297] Lustre: server umount lustre-OST0000 complete [ 3449.313594] LustreError: 33811: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. [ 3449.323236] LustreError: 33811:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 3469.732842] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3476.267290] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3477.499328] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3547.571676] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 20:04:48 (1763341488) [ 3550.377448] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3552.052312] Lustre: Failing over lustre-MDT0000 [ 3552.325989] Lustre: server umount lustre-MDT0000 complete [ 3568.207555] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3568.210064] Lustre: Skipped 5 previous similar messages [ 3569.282398] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2998 to 0x280000400:3041) [ 3569.282405] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3030 to 0x240000400:3073) [ 3571.447808] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3573.218499] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763341499/real 1763341499] req@ffff935eaacb7480 x1848993961645184/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763341515 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3573.226716] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 28 previous similar messages [ 3642.626743] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 20:06:23 (1763341583) [ 3644.428547] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3644.432455] Lustre: Skipped 2 previous similar messages [ 3644.436259] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3644.439035] Lustre: Skipped 11 previous similar messages [ 3656.164337] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 20:06:37 (1763341597) [ 3659.297714] Lustre: Failing over lustre-MDT0000 [ 3659.623190] Lustre: server umount lustre-MDT0000 complete [ 3686.566437] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e48e4722 [ 3687.475189] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 3687.477430] LustreError: 99269:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935e867efb80 x1848993946235776/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:636/0 lens 328/344 e 0 to 0 dl 1763341641 ref 1 fl Complete:/240/0 rc 0/0 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 3691.720339] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3702.804891] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 1:25 [ 3702.932526] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3085 to 0x240000400:3105) [ 3702.934230] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3052 to 0x280000400:3073) [ 3706.644473] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3708.380750] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3716.813603] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 20:07:37 (1763341657) [ 3718.950168] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 3723.612232] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3725.323096] Lustre: Failing over lustre-MDT0000 [ 3725.587910] Lustre: server umount lustre-MDT0000 complete [ 3753.443160] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e48e4b0b [ 3757.736246] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3761.224957] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3085 to 0x240000400:3137) [ 3761.225746] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3075 to 0x280000400:3105) [ 3765.383191] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3767.047144] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3775.929796] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 20:08:37 (1763341717) [ 3777.047606] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 3781.656586] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3783.205861] Lustre: Failing over lustre-MDT0000 [ 3783.438242] Lustre: server umount lustre-MDT0000 complete [ 3803.703150] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3085 to 0x240000400:3169) [ 3803.703805] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3107 to 0x280000400:3137) [ 3805.013717] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3811.005124] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3812.172563] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3818.936773] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 20:09:20 (1763341760) [ 3819.734350] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 3824.484471] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3825.987027] Lustre: Failing over lustre-MDT0000 [ 3826.276972] Lustre: server umount lustre-MDT0000 complete [ 3846.247700] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3171 to 0x240000400:3201) [ 3846.251077] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3107 to 0x280000400:3169) [ 3846.691639] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3857.175735] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 20:09:58 (1763341798) [ 3859.317289] Lustre: *** cfs_fail_loc=13b, val=315*** [ 3859.319242] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 3859.327168] LustreError: 103871:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935d870b4a80 x1848993946284032/t257698037777(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:53/0 lens 392/456 e 0 to 0 dl 1763341813 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 3862.326472] Lustre: Failing over lustre-MDT0000 [ 3862.877213] Lustre: server umount lustre-MDT0000 complete [ 3894.069762] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3900.559583] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3171 to 0x280000400:3201) [ 3900.559707] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3171 to 0x240000400:3233) [ 3900.577289] Lustre: 105109:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935d81dedc00 x1848993946284032/t257698037777(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:94/0 lens 392/456 e 0 to 0 dl 1763341854 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 3903.597926] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3905.075995] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3913.129866] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 20:10:54 (1763341854) [ 3913.970804] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3913.978559] LustreError: 105107:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935e84c29880 x1848993946299136/t261993005072(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:107/0 lens 504/448 e 0 to 0 dl 1763341867 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3918.511475] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3919.971469] Lustre: Failing over lustre-MDT0000 [ 3920.234184] Lustre: server umount lustre-MDT0000 complete [ 3936.835473] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3936.840876] LustreError: Skipped 8 previous similar messages [ 3937.157973] 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 [ 3937.183051] Lustre: Skipped 21 previous similar messages [ 3937.379544] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3937.392320] Lustre: Skipped 11 previous similar messages [ 3940.520403] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3171 to 0x240000400:3265) [ 3940.523624] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3203 to 0x280000400:3233) [ 3940.553061] Lustre: 106623:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935ebede0380 x1848993946299136/t261993005072(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:134/0 lens 504/2880 e 0 to 0 dl 1763341894 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3940.737584] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3947.438609] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3948.808569] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3956.183925] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 20:11:37 (1763341897) [ 3956.994170] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3957.002953] LustreError: 106622:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935d870b6a00 x1848993946312832/t266287972368(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:150/0 lens 504/448 e 0 to 0 dl 1763341910 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3958.706207] Lustre: *** cfs_fail_loc=13b, val=315*** [ 3961.324844] LustreError: 107594:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3961.329649] LustreError: 107594:0:(osd_handler.c:720:osd_ro()) Skipped 5 previous similar messages [ 3962.284669] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3964.255927] Lustre: Failing over lustre-MDT0000 [ 3964.458292] LustreError: 107740:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 3964.461732] LustreError: 107740:0:(obd_class.h:479:obd_check_dev()) Skipped 61 previous similar messages [ 3964.540244] Lustre: server umount lustre-MDT0000 complete [ 3983.451784] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3983.467798] Lustre: Skipped 9 previous similar messages [ 3983.585824] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3983.589363] Lustre: Skipped 9 previous similar messages [ 3983.644092] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3203 to 0x280000400:3265) [ 3983.650569] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3267 to 0x240000400:3297) [ 3983.663867] Lustre: 108139:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935d84e1d180 x1848993946313088/t266287972369(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:177/0 lens 392/456 e 0 to 0 dl 1763341937 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 3983.711082] Lustre: 108139:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 1 previous similar message [ 3986.878949] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3997.998169] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 20:12:19 (1763341939) [ 3998.918281] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3998.922393] Lustre: Skipped 1 previous similar message [ 3998.924712] LustreError: 108137:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935d84e45f80 x1848993946326400/t270582939664(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:192/0 lens 504/448 e 0 to 0 dl 1763341952 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3998.960452] LustreError: 108137:0:(ldlm_lib.c:3324:target_send_reply_msg()) Skipped 1 previous similar message [ 4000.652334] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4000.656069] Lustre: Skipped 1 previous similar message [ 4004.502883] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4006.170985] Lustre: Failing over lustre-MDT0000 [ 4006.411641] Lustre: server umount lustre-MDT0000 complete [ 4035.041648] LustreError: 3315:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff935e84c28a80 x1848993961784448/t0(0) o250->MGC192.168.202.124@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 [ 4039.878683] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4040.914687] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3203 to 0x280000400:3297) [ 4040.914981] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3329) [ 4040.949708] Lustre: 109609:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935e85e55180 x1848993946326400/t270582939664(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:234/0 lens 504/2880 e 0 to 0 dl 1763341994 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4051.125465] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 20:13:12 (1763341992) [ 4052.160310] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4053.800558] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4053.802386] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 4053.809814] LustreError: 109612:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935eac4d1f80 x1848993946339456/t274877906960(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:247/0 lens 392/456 e 0 to 0 dl 1763342007 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4057.733557] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4059.317591] Lustre: Failing over lustre-MDT0000 [ 4059.552690] Lustre: server umount lustre-MDT0000 complete [ 4075.489854] LustreError: 110972: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. [ 4075.511716] LustreError: 110972:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 4078.676328] Lustre: 110976:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935ebede3800 x1848993946339456/t274877906960(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:272/0 lens 392/456 e 0 to 0 dl 1763342032 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4078.695479] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3361) [ 4078.709953] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3299 to 0x280000400:3329) [ 4079.637980] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4090.587521] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 20:13:51 (1763342031) [ 4091.500213] Lustre: *** cfs_fail_loc=12b, val=2147483991*** [ 4091.504656] LustreError: 110972:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935e8662e680 x1848993946349312/t279172874255(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:285/0 lens 664/608 e 0 to 0 dl 1763342045 ref 1 fl Interpret:/600/0 rc 301/0 job:'touch.0' uid:0 gid:0 projid:0 [ 4106.784415] Lustre: 110977:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935eac7c4700 x1848993946349312/t279172874255(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:300/0 lens 664/3488 e 0 to 0 dl 1763342060 ref 1 fl Interpret:/602/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:0 [ 4113.393599] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 20:14:14 (1763342054) [ 4116.964143] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4118.661902] Lustre: Failing over lustre-MDT0000 [ 4118.974789] Lustre: server umount lustre-MDT0000 complete [ 4139.786252] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4144.774992] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3393) [ 4144.775685] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3331 to 0x280000400:3361) [ 4148.227712] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4149.482751] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4167.597958] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 20:15:08 (1763342108) [ 4173.103989] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4175.119039] Lustre: Failing over lustre-MDT0000 [ 4175.470143] Lustre: server umount lustre-MDT0000 complete [ 4193.415293] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4193.418041] Lustre: Skipped 10 previous similar messages [ 4193.743994] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763342120/real 1763342120] req@ffff935e8662f480 x1848993961831424/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763342136 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4193.769085] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 77 previous similar messages [ 4195.096665] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3331 to 0x280000400:3393) [ 4195.097272] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3395 to 0x240000400:3425) [ 4197.446752] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4204.978404] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4206.824222] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4211.855288] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4223.389313] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 20:16:04 (1763342164) [ 4267.516587] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4269.413045] Lustre: Failing over lustre-MDT0000 [ 4270.050068] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4270.053376] Lustre: Skipped 1 previous similar message [ 4272.168660] Lustre: server umount lustre-MDT0000 complete [ 4294.042865] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4299.530381] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4705) [ 4299.530742] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4644 to 0x280000400:4673) [ 4302.673353] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4304.058995] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4309.737408] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4309.739398] Lustre: Skipped 25 previous similar messages [ 4356.668211] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 20:18:17 (1763342297) [ 4361.201376] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4363.121729] Lustre: Failing over lustre-MDT0000 [ 4363.540813] Lustre: server umount lustre-MDT0000 complete [ 4386.215528] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4389.113944] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4737) [ 4389.117652] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4675 to 0x280000400:4705) [ 4394.119561] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4395.898450] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4403.089806] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid [ 4404.430591] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 4409.719559] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 20:19:11 (1763342351) [ 4416.282768] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 4432.402520] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnecting [ 4432.413391] Lustre: Skipped 2 previous similar messages [ 4434.659308] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4434.662066] Lustre: Skipped 1 previous similar message [ 4434.665801] LustreError: 117820:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935d833dc850 x1848993949129472/t296352743435(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:628/0 lens 66040/440 e 0 to 0 dl 1763342388 ref 1 fl Interpret:/600/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 4450.852227] Lustre: 117819:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935d856c4700 x1848993949129472/t296352743435(0) o36->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:644/0 lens 66040/440 e 0 to 0 dl 1763342404 ref 1 fl Interpret:/602/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 4461.329297] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 4462.864330] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 20:20:03 (1763342403) [ 4472.847559] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4475.773938] Lustre: Failing over lustre-MDT0000 [ 4476.289670] Lustre: server umount lustre-MDT0000 complete [ 4509.528408] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4518.904639] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4839 to 0x240000400:4865) [ 4518.906335] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4806 to 0x280000400:4833) [ 4522.932345] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4524.684840] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4535.604848] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 20:21:16 (1763342476) [ 4560.003400] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 4573.839086] Lustre: Failing over lustre-OST0000 [ 4573.929071] LustreError: 121449:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 4573.932112] LustreError: 121449:0:(obd_class.h:479:obd_check_dev()) Skipped 47 previous similar messages [ 4574.015897] Lustre: server umount lustre-OST0000 complete [ 4575.199620] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4575.204864] 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 [ 4575.216974] Lustre: Skipped 16 previous similar messages [ 4575.221112] LustreError: 33811: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. [ 4575.248631] LustreError: 33811:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 4590.890429] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4590.896037] Lustre: Skipped 8 previous similar messages [ 4592.076488] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4592.079702] Lustre: Skipped 7 previous similar messages [ 4596.368925] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4610.903419] Lustre: Failing over lustre-OST0000 [ 4610.912600] LustreError: 122407:0:(ldlm_lib.c:2982:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 4610.916331] Lustre: 121860:0:(ldlm_lib.c:2385:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4610.921083] Lustre: 121860:0:(ldlm_lib.c:2385:target_recovery_overseer()) Skipped 2 previous similar messages [ 4610.925980] Lustre: 121860:0:(ldlm_lib.c:1897:abort_req_replay_queue()) @@@ aborted: req@ffff935d821d7800 x1848993962606208/t0(17179870644) o6->lustre-MDT0000-mdtlov_UUID@0@lo:54/0 lens 544/0 e 2 to 0 dl 1763342569 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 4610.936453] LustreError: 121860:0:(ofd_obd.c:1293:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 4610.941539] Lustre: lustre-OST0000: Recovery over after 0:18, of 2 clients 0 recovered and 2 were evicted. [ 4610.944748] Lustre: Skipped 7 previous similar messages [ 4610.948667] LustreError: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -19 [ 4610.953099] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 4611.030874] Lustre: server umount lustre-OST0000 complete [ 4632.705655] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4636.499949] LustreError: 3315:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 0, old was -19 req@ffff935e8662fb80 x1848993962606208/t17179870644(17179870644) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 3 to 0 dl 1763342600 ref 2 fl Interpret:RQU/204/0 rc 0/0 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 4640.435935] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 4641.989414] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4682.830973] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 20:23:43 (1763342623) [ 4685.158385] Lustre: Failing over lustre-MDT0000 [ 4685.488618] Lustre: server umount lustre-MDT0000 complete [ 4703.129845] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4703.134493] LustreError: Skipped 8 previous similar messages [ 4707.901935] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4712.115348] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5281) [ 4712.120156] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5249) [ 4722.019908] Lustre: Failing over lustre-MDT0000 [ 4722.145809] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4722.159867] Lustre: Skipped 1 previous similar message [ 4722.366719] Lustre: server umount lustre-MDT0000 complete [ 4741.751701] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5281) [ 4741.758692] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5313) [ 4743.009711] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4750.229635] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4752.111639] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4759.788257] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 20:25:00 (1763342700) [ 4774.337111] Lustre: Failing over lustre-OST0000 [ 4775.392816] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4775.399335] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 4775.415307] Lustre: Skipped 1 previous similar message [ 4776.545445] Lustre: server umount lustre-OST0000 complete [ 4794.241818] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4794.253414] Lustre: Skipped 7 previous similar messages [ 4799.786861] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4806.430048] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 4808.277859] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4817.013935] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 20:25:58 (1763342758) [ 4819.025776] Lustre: Failing over lustre-MDT0000 [ 4819.421723] Lustre: server umount lustre-MDT0000 complete [ 4827.937081] Lustre: *** cfs_fail_loc=605, val=0*** [ 4827.938991] LustreError: 127795:0:(llog_obd.c:190:llog_setup()) MGS: ctxt 0 lop_setup=ffffffffc1361d10 failed: rc = -95 [ 4827.947972] LustreError: 127795:0:(obd_config.c:783:class_setup()) setup MGS failed (-95) [ 4827.951132] LustreError: 127795:0:(obd_mount.c:193:lustre_start_simple()) MGS setup error -95 [ 4827.955555] LustreError: 127795:0:(tgt_mount.c:117:server_deregister_mount()) MGS not registered [ 4827.960039] LustreError: Failed to start MGS 'MGS' (-95). Is the 'mgs' module loaded? [ 4827.963645] LustreError: 127795:0:(tgt_mount.c:1973:server_put_super()) no obd lustre-MDT0000 [ 4828.064766] Lustre: server umount lustre-MDT0000 complete [ 4828.068809] LustreError: 127795:0:(super25.c:199:lustre_fill_super()) llite: Unable to mount : rc = -95 [ 4833.988720] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5283 to 0x280000400:5313) [ 4833.994540] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5315 to 0x240000400:5345) [ 4835.487331] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763342762/real 1763342762] req@ffff935d83e2df80 x1848993962779008/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763342778 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4835.509275] Lustre: 3316:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 28 previous similar messages [ 4837.543914] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4847.077893] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 20:26:28 (1763342788) [ 4849.967537] LustreError: 128774:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4849.982604] LustreError: 128774:0:(osd_handler.c:720:osd_ro()) Skipped 8 previous similar messages [ 4850.768925] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4853.883468] Lustre: Failing over lustre-MDT0000 [ 4854.223437] Lustre: server umount lustre-MDT0000 complete [ 4879.586157] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x66620727e493d51e [ 4879.889962] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.24@tcp (not set up) [ 4881.698270] Lustre: *** cfs_fail_loc=707, val=0*** [ 4885.195745] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4898.362263] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:52 [ 4898.965117] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5359 to 0x240000400:5377) [ 4898.972938] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5326 to 0x280000400:5345) [ 4903.108704] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4904.674436] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4913.524300] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 20:27:34 (1763342854) [ 4944.664989] LustreError: 129392:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935e86df8000 x1848993950000000/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:383/0 lens 664/0 e 0 to 0 dl 1763342898 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 4944.683311] LustreError: 129392:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 11000ms [ 4955.769906] LustreError: 129392:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 4955.796974] LustreError: 129395:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935eab60ed80 x1848993950000768/t0(0) o35->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:400/0 lens 392/0 e 0 to 0 dl 1763342915 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 4957.641387] LustreError: 129392:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935eab60d500 x1848993950006656/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:435/0 lens 576/0 e 0 to 0 dl 1763342950 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 4957.657495] LustreError: 129392:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 27 previous similar messages [ 4960.310198] LustreError: 33820:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935d8a85dc00 x1848993962819328/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:399/0 lens 544/0 e 0 to 0 dl 1763342914 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 4960.335667] LustreError: 33820:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 20 previous similar messages [ 4965.346717] LustreError: 33819:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935e85c60a80 x1848993962820992/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:404/0 lens 544/0 e 0 to 0 dl 1763342919 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 4965.356163] LustreError: 33819:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 2 previous similar messages [ 4974.615891] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 20:28:35 (1763342915) [ 5006.506903] LustreError: 32957:0:(tgt_handler.c:2782:tgt_brw_write()) cfs_fail_timeout id 224 sleeping for 11000ms [ 5017.599156] LustreError: 32957:0:(tgt_handler.c:2782:tgt_brw_write()) cfs_fail_timeout id 224 awake [ 5026.580326] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 20:29:27 (1763342967) [ 5055.104257] LustreError: 129394:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935eac4d1f80 x1848993950022400/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:493/0 lens 576/0 e 0 to 0 dl 1763343008 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 5055.128992] LustreError: 129394:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 4 previous similar messages [ 5055.146876] LustreError: 129394:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 5000ms [ 5060.159218] LustreError: 129394:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 5072.679161] LustreError: 129394:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 5072.710697] LustreError: 129394:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935eab71d500 x1848993950044544/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:550/0 lens 664/0 e 0 to 0 dl 1763343065 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 5072.740614] LustreError: 129394:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 120 previous similar messages [ 5091.082952] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 20:30:32 (1763343032) [ 5184.478465] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 20:32:05 (1763343125) [ 5212.963153] LustreError: 129392:0:(service.c:2536:ptlrpc_server_handle_request()) @@@ HIT req@ffff935e8662c000 x1848993950096384/t0(0) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:651/0 lens 576/0 e 0 to 0 dl 1763343166 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 5212.980574] LustreError: 129392:0:(service.c:2536:ptlrpc_server_handle_request()) Skipped 98 previous similar messages [ 5212.983963] LustreError: 129392:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 5212.987396] LustreError: 129392:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 1 previous similar message [ 5213.407245] LustreError: 129392:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 5229.407708] LustreError: 129395:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 5229.411929] LustreError: 129395:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 37 previous similar messages [ 5229.833274] LustreError: 129395:0:(service.c:2537:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 5229.854429] LustreError: 129395:0:(service.c:2537:ptlrpc_server_handle_request()) Skipped 37 previous similar messages [ 5263.333235] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 20:33:24 (1763343204) [ 5297.188882] Lustre: DEBUG MARKER: phase 2 [ 5307.254373] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 20:34:07 (1763343247) [ 5391.171407] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 20:35:32 (1763343332) [ 5392.458056] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 5393.964532] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 1mdts recovery; 1 clients ========================================================== 20:35:35 (1763343335) [ 5397.785626] Lustre: DEBUG MARKER: Started rundbench load pid=126640 ... [ 5402.635681] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5404.783642] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 5406.531355] Lustre: Failing over lustre-MDT0000 [ 5406.596964] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.24@tcp (stopping) [ 5406.744208] LustreError: 136301:0:(obd_class.h:479:obd_check_dev()) Device 11 not setup [ 5406.766342] LustreError: 136301:0:(obd_class.h:479:obd_check_dev()) Skipped 29 previous similar messages [ 5406.892857] Lustre: server umount lustre-MDT0000 complete [ 5423.520407] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5423.530633] LustreError: Skipped 3 previous similar messages [ 5423.640555] LustreError: 136703:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5423.667118] LustreError: 136703:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 5423.941995] 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 [ 5423.959894] Lustre: Skipped 9 previous similar messages [ 5424.115467] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5424.119115] Lustre: Skipped 2 previous similar messages [ 5424.177909] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5424.194914] Lustre: Skipped 6 previous similar messages [ 5425.622397] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5425.626380] Lustre: Skipped 6 previous similar messages [ 5426.483280] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5426.491622] Lustre: Skipped 6 previous similar messages [ 5426.549693] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5479 to 0x240000400:5505) [ 5426.551599] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5425 to 0x280000400:5441) [ 5428.488525] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5429.218836] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5429.226601] Lustre: Skipped 16 previous similar messages [ 5435.599302] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5437.334457] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5444.421205] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5446.809259] Lustre: DEBUG MARKER: test_70b fail mds1 2 times [ 5448.430615] Lustre: Failing over lustre-MDT0000 [ 5448.728849] Lustre: server umount lustre-MDT0000 complete [ 5467.104146] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763343392/real 1763343392] req@ffff935d89d85c00 x1848993963025152/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763343408 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5467.142868] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 21 previous similar messages [ 5469.546278] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5484.407935] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5469 to 0x280000400:5505) [ 5484.413672] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5532 to 0x240000400:5569) [ 5488.294230] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5489.693227] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5494.815748] LustreError: 138679:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5494.823226] LustreError: 138679:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 5495.826910] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5497.985677] Lustre: DEBUG MARKER: test_70b fail mds1 3 times [ 5499.481348] Lustre: Failing over lustre-MDT0000 [ 5499.699647] Lustre: server umount lustre-MDT0000 complete [ 5519.750650] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5520.253459] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5606 to 0x240000400:5633) [ 5520.253902] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5543 to 0x280000400:5569) [ 5527.068781] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5528.645666] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5549.199515] Lustre: DEBUG MARKER: == replay-single test 70c: tar 1mdts recovery ============ 20:38:10 (1763343490) [ 5674.482319] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5686.280302] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 5688.014215] Lustre: Failing over lustre-MDT0000 [ 5688.503934] Lustre: server umount lustre-MDT0000 complete [ 5710.288226] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5715.759247] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6269 to 0x280000400:6305) [ 5715.764057] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6334 to 0x240000400:6369) [ 5719.321520] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5720.837562] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5848.578926] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5861.610780] Lustre: DEBUG MARKER: test_70c fail mds1 2 times [ 5864.014594] Lustre: Failing over lustre-MDT0000 [ 5864.474951] Lustre: server umount lustre-MDT0000 complete [ 5887.524571] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5907.511221] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6918 to 0x240000400:6945) [ 5907.514657] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6853 to 0x280000400:6881) [ 5912.954768] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5914.463878] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5958.362363] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 1mdts recovery ========================================================== 20:44:59 (1763343899) [ 5959.883200] Lustre: DEBUG MARKER: SKIP: replay-single test_70d needs >= 2 MDTs [ 5961.277286] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 20:45:02 (1763343902) [ 5962.671410] Lustre: DEBUG MARKER: SKIP: replay-single test_70e needs >= 2 MDTs [ 5964.160135] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 20:45:05 (1763343905) [ 5971.538834] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5974.177622] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 5976.215261] Lustre: Failing over lustre-OST0000 [ 5976.273667] Lustre: server umount lustre-OST0000 complete [ 6000.576510] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6008.634871] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6011.411398] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6023.107773] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6025.938442] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 6028.581129] Lustre: Failing over lustre-OST0000 [ 6028.652140] LustreError: 145035:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 6028.654612] LustreError: 145035:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 6028.691408] Lustre: server umount lustre-OST0000 complete [ 6029.815457] 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 [ 6029.821264] Lustre: Skipped 10 previous similar messages [ 6029.823978] LustreError: 33812: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. [ 6029.831666] LustreError: 33812:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 6046.167150] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6046.169761] Lustre: Skipped 5 previous similar messages [ 6046.174948] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 6046.185665] Lustre: Skipped 5 previous similar messages [ 6047.374938] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 6047.378621] Lustre: Skipped 5 previous similar messages [ 6047.883047] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 6047.887303] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 6047.887314] Lustre: Skipped 10 previous similar messages [ 6047.914670] Lustre: Skipped 5 previous similar messages [ 6052.123315] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6059.380503] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6061.210103] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6072.077577] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 20:46:53 (1763344013) [ 6073.547934] Lustre: DEBUG MARKER: SKIP: replay-single test_71a needs >= 2 MDTs [ 6075.429943] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 20:46:56 (1763344016) [ 6079.251240] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6081.964485] Lustre: Failing over lustre-MDT0000 [ 6082.024870] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6082.282056] Lustre: server umount lustre-MDT0000 complete [ 6099.057854] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6099.066257] LustreError: Skipped 4 previous similar messages [ 6100.059899] Lustre: *** cfs_fail_loc=302, val=2147483648*** [ 6103.409450] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6115.875548] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:54 [ 6116.021110] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6958 to 0x240000400:6977) [ 6116.026276] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6894 to 0x280000400:6913) [ 6120.676898] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6122.290219] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6131.045370] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 20:47:51 (1763344071) [ 6134.291323] LustreError: 147960:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6134.295646] LustreError: 147960:0:(osd_handler.c:720:osd_ro()) Skipped 5 previous similar messages [ 6135.211560] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6137.884066] Lustre: Failing over lustre-MDT0000 [ 6138.232310] Lustre: server umount lustre-MDT0000 complete [ 6157.395540] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 6157.408215] LustreError: 148560:0:(ldlm_lib.c:3324:target_send_reply_msg()) @@@ dropping reply req@ffff935ec172ca80 x1848993960821248/t343597383683(343597383683) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:86/0 lens 592/608 e 0 to 0 dl 1763344111 ref 1 fl Interpret:/604/0 rc 301/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 6158.816863] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763344085/real 1763344085] req@ffff935ec1778700 x1848993964296448/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1763344101 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6158.830572] Lustre: 3318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 25 previous similar messages [ 6161.359165] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6172.723646] Lustre: lustre-MDT0000: Client e6eb6064-a37e-4bc3-b753-dbe720727416 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:54 [ 6172.732782] Lustre: 148560:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff935ebf9fb800 x1848993960821248/t343597383683(343597383683) o101->e6eb6064-a37e-4bc3-b753-dbe720727416@192.168.202.24@tcp:101/0 lens 592/3488 e 0 to 0 dl 1763344126 ref 1 fl Interpret:/606/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 6172.902250] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6958 to 0x240000400:7009) [ 6172.906870] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6915 to 0x280000400:6945) [ 6176.885490] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6178.626748] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6186.559133] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 20:48:47 (1763344127) [ 6189.346772] Lustre: Failing over lustre-OST0000 [ 6189.508661] Lustre: server umount lustre-OST0000 complete [ 6193.796259] Lustre: Failing over lustre-MDT0000 [ 6194.168593] Lustre: server umount lustre-MDT0000 complete [ 6212.096065] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6915 to 0x280000400:6977) [ 6216.250558] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6223.892466] Lustre: lustre-OST0000: Denying connection for new client d778081a-e85a-495c-b574-62b0d2cc82f3 (at 192.168.202.24@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 6223.914963] Lustre: Skipped 11 previous similar messages [ 6225.183868] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6958 to 0x240000400:7041) [ 6229.274417] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6239.630271] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 20:49:40 (1763344180) [ 6241.026683] Lustre: DEBUG MARKER: SKIP: replay-single test_80a needs >= 2 MDTs [ 6242.711691] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 20:49:43 (1763344183) [ 6244.088447] Lustre: DEBUG MARKER: SKIP: replay-single test_80b needs >= 2 MDTs [ 6245.789386] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 20:49:46 (1763344186) [ 6247.235885] Lustre: DEBUG MARKER: SKIP: replay-single test_80c needs >= 2 MDTs [ 6248.834924] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 20:49:49 (1763344189) [ 6250.413795] Lustre: DEBUG MARKER: SKIP: replay-single test_80d needs >= 2 MDTs [ 6252.123761] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 20:49:53 (1763344193) [ 6253.498967] Lustre: DEBUG MARKER: SKIP: replay-single test_80e needs >= 2 MDTs [ 6255.124435] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 20:49:56 (1763344196) [ 6256.761811] Lustre: DEBUG MARKER: SKIP: replay-single test_80f needs >= 2 MDTs [ 6258.787511] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 20:49:59 (1763344199) [ 6260.375752] Lustre: DEBUG MARKER: SKIP: replay-single test_80g needs >= 2 MDTs [ 6262.020974] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 20:50:03 (1763344203) [ 6263.621233] Lustre: DEBUG MARKER: SKIP: replay-single test_80h needs >= 2 MDTs [ 6265.577347] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 20:50:06 (1763344206) [ 6267.446960] Lustre: DEBUG MARKER: SKIP: replay-single test_81a needs >= 2 MDTs [ 6269.499711] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 20:50:10 (1763344210) [ 6271.126811] Lustre: DEBUG MARKER: SKIP: replay-single test_81b needs >= 2 MDTs [ 6273.172763] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 20:50:13 (1763344213) [ 6274.684921] Lustre: DEBUG MARKER: SKIP: replay-single test_81c needs >= 2 MDTs [ 6276.503772] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 20:50:17 (1763344217) [ 6278.012472] Lustre: DEBUG MARKER: SKIP: replay-single test_81d needs >= 2 MDTs [ 6280.164528] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 20:50:20 (1763344220) [ 6281.979948] Lustre: DEBUG MARKER: SKIP: replay-single test_81e needs >= 2 MDTs [ 6283.756980] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 20:50:24 (1763344224) [ 6285.296612] Lustre: DEBUG MARKER: SKIP: replay-single test_81f needs >= 2 MDTs [ 6286.980827] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 20:50:28 (1763344228) [ 6288.424963] Lustre: DEBUG MARKER: SKIP: replay-single test_81g needs >= 2 MDTs [ 6289.964211] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 20:50:31 (1763344231) [ 6291.586695] Lustre: DEBUG MARKER: SKIP: replay-single test_81h needs >= 2 MDTs [ 6293.322501] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 20:50:34 (1763344234) [ 6295.338763] Lustre: 152955:0:(genops.c:1791:obd_export_evict_by_uuid()) lustre-MDT0000: evicting d778081a-e85a-495c-b574-62b0d2cc82f3 at adminstrative request [ 6304.581493] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 20:50:45 (1763344245) [ 6312.667321] Lustre: Failing over lustre-MDT0000 [ 6313.127468] Lustre: server umount lustre-MDT0000 complete [ 6333.019615] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:7029 to 0x280000400:7073) [ 6333.021244] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7093 to 0x240000400:7137) [ 6335.642729] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6342.783082] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6344.464677] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6352.990729] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 20:51:33 (1763344293) [ 6370.328943] Lustre: Failing over lustre-OST0000 [ 6370.575495] Lustre: server umount lustre-OST0000 complete [ 6371.811779] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6393.500862] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6401.354960] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6403.249945] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6412.092316] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 20:52:33 (1763344353) [ 6416.618178] Lustre: Failing over lustre-MDT0000 [ 6417.157602] Lustre: server umount lustre-MDT0000 complete [ 6424.173091] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:7029 to 0x280000400:7105) [ 6424.181552] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7238 to 0x240000400:7265) [ 6428.168299] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6436.801527] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 20:52:57 (1763344377) [ 6440.432305] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6442.374657] Lustre: Failing over lustre-OST0000 [ 6442.421163] Lustre: server umount lustre-OST0000 complete [ 6444.525766] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6465.073413] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6471.267840] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6472.671396] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6480.999926] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 20:53:41 (1763344421) [ 6485.083278] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6488.517328] Lustre: Failing over lustre-OST0000 [ 6488.558054] Lustre: server umount lustre-OST0000 complete [ 6506.179439] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.202.24@tcp inode [0x200029441:0x5:0x0] object 0x240000400:7267 extent [0-1048575]: client csum 900c0b7d, server csum b92024a8 [ 6509.513619] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6515.999747] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6517.347549] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6524.779443] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 20:54:25 (1763344465) [ 6527.700574] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6530.301942] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6534.907880] Lustre: Failing over lustre-MDT0000 [ 6535.138606] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6535.149321] Lustre: Skipped 4 previous similar messages [ 6535.252139] Lustre: server umount lustre-MDT0000 complete [ 6538.145242] Lustre: Failing over lustre-OST0000 [ 6538.148676] LustreError: 116834:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1763344480 with bad export cookie 7377467007507070013 [ 6538.156741] LustreError: 116834:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 6540.219530] Lustre: server umount lustre-OST0000 complete [ 6564.756507] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:7120 to 0x280000400:7137) [ 6566.341755] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6583.568142] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7292 to 0x240000400:7297) [ 6585.454791] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6597.888986] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 20:55:38 (1763344538) [ 6612.149386] Lustre: Failing over lustre-OST0000 [ 6614.251200] Lustre: server umount lustre-OST0000 complete [ 6617.661370] Lustre: Failing over lustre-MDT0000 [ 6618.106180] Lustre: server umount lustre-MDT0000 complete [ 6630.419027] LustreError: 33820:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6630.435161] LustreError: 33820:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 49 previous similar messages [ 6634.471503] 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 [ 6634.483675] Lustre: Skipped 16 previous similar messages [ 6635.868597] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:7120 to 0x280000400:7169) [ 6638.209453] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6649.504790] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6651.674503] Lustre: lustre-OST0000: Denying connection for new client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:04 [ 6651.693226] Lustre: Skipped 1 previous similar message [ 6672.403483] Lustre: lustre-OST0000: Denying connection for new client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:43 [ 6672.411770] Lustre: Skipped 3 previous similar messages [ 6708.250386] Lustre: lustre-OST0000: Denying connection for new client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:07 [ 6708.261454] Lustre: Skipped 6 previous similar messages [ 6716.004360] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 6716.008441] Lustre: 164196:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client 86b1d640-a385-49c4-8ae3-c73727ad8b80@ [ 6716.019777] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 6716.069329] Lustre: lustre-OST0000: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 6716.074871] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 6716.084737] Lustre: Skipped 10 previous similar messages [ 6716.090390] Lustre: Skipped 16 previous similar messages [ 6716.097208] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7308 to 0x240000400:7329) [ 6720.837847] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 62 sec [ 6732.896831] Lustre: DEBUG MARKER: free_before: 7518208 free_after: 7518208 [ 6738.932402] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 20:58:00 (1763344680) [ 6743.283416] Lustre: Failing over lustre-OST0000 [ 6743.351169] LustreError: 165361:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 6743.354963] LustreError: 165361:0:(obd_class.h:479:obd_check_dev()) Skipped 55 previous similar messages [ 6743.395297] Lustre: server umount lustre-OST0000 complete [ 6761.003882] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6761.006844] Lustre: Skipped 13 previous similar messages [ 6761.012848] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 6761.020264] Lustre: Skipped 11 previous similar messages [ 6762.646023] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 6762.652136] Lustre: Skipped 11 previous similar messages [ 6766.523655] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6777.287988] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 20:58:38 (1763344718) [ 6780.925063] Lustre: Failing over lustre-OST0000 [ 6781.014669] Lustre: server umount lustre-OST0000 complete [ 6798.293781] LustreError: 167047:0:(ldlm_lib.c:2883:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 40000ms [ 6798.298579] LustreError: 167047:0:(ldlm_lib.c:2883:target_recovery_thread()) Skipped 79 previous similar messages [ 6801.284758] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6804.447966] Lustre: *** cfs_fail_loc=715, val=40*** [ 6813.763692] Lustre: lustre-OST0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 2 clients in recovery for 1:25 [ 6814.687436] Lustre: 3315:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1763344741/real 1763344741] req@ffff935e98086300 x1848993964503936/t0(0) o400->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 224/224 e 0 to 1 dl 1763344757 ref 1 fl Rpc:XQr/2c0/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 6814.708229] Lustre: 3315:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 19 previous similar messages [ 6814.729365] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 1:24 [ 6819.808717] Lustre: *** cfs_fail_loc=715, val=40*** [ 6819.810689] Lustre: Skipped 1 previous similar message [ 6820.831463] Lustre: *** cfs_fail_loc=715, val=40*** [ 6830.100880] Lustre: lustre-OST0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 2 clients in recovery for 1:08 [ 6836.191692] Lustre: *** cfs_fail_loc=715, val=40*** [ 6838.391143] LustreError: 167047:0:(ldlm_lib.c:2883:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 6838.394774] LustreError: 167047:0:(ldlm_lib.c:2883:target_recovery_thread()) Skipped 79 previous similar messages [ 6841.634471] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6842.755277] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6848.942156] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 20:59:50 (1763344790) [ 6852.518679] Lustre: Failing over lustre-MDT0000 [ 6852.909622] Lustre: server umount lustre-MDT0000 complete [ 6870.145513] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6870.151927] LustreError: Skipped 6 previous similar messages [ 6871.088893] LustreError: 168486:0:(ldlm_lib.c:2883:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 80000ms [ 6874.089992] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6877.151127] Lustre: *** cfs_fail_loc=715, val=80*** [ 6877.157309] Lustre: Skipped 1 previous similar message [ 6887.443720] Lustre: lustre-MDT0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 6887.449983] Lustre: Skipped 1 previous similar message [ 6893.535189] Lustre: *** cfs_fail_loc=715, val=80*** [ 6902.803370] Lustre: lustre-MDT0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:38 [ 6919.197499] Lustre: lustre-MDT0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:21 [ 6925.279232] Lustre: *** cfs_fail_loc=715, val=80*** [ 6925.280965] Lustre: Skipped 1 previous similar message [ 6935.590388] Lustre: lustre-MDT0000: Client 7137cf90-9cdf-4019-95c0-9689a5a0deb8 (at 192.168.202.24@tcp) reconnected, waiting for 1 clients in recovery for 0:05 [ 6951.191233] LustreError: 168486:0:(ldlm_lib.c:2883:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 6951.241858] Lustre: 168486:0:(ldlm_lib.c:2929:target_recovery_thread()) too long recovery - read logs [ 6951.248251] LustreError: dumping log to /tmp/lustre-log.1763344893.168486 [ 6951.411344] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:7182 to 0x280000400:7201) [ 6951.415824] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7343 to 0x240000400:7361) [ 6955.386755] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6957.046938] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6965.138212] Lustre: DEBUG MARKER: == replay-single test complete, duration 6725 sec ======== 21:01:46 (1763344906) [ 6966.653355] Lustre: DEBUG MARKER: === replay-single: start cleanup 21:01:47 (1763344907) === [ 6975.932379] Lustre: DEBUG MARKER: === replay-single: finish cleanup 21:01:56 (1763344916) === [ 7008.344447] Lustre: server umount lustre-MDT0000 complete [ 7012.228906] LustreError: 5774:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1763344954 with bad export cookie 7377467007507082109 [ 7021.658644] Lustre: server umount lustre-OST0000 complete [ 7025.724781] Lustre: server umount lustre-OST0001 complete [ 7036.243903] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing unload_modules_local [ 7038.745335] Key type lgssc unregistered [ 7039.007383] LNet: 170494:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 7039.011688] LNetError: 170494:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 7039.028099] LNet: Removed LNI 192.168.202.124@tcp [ 7039.689340] Key type .llcrypt unregistered [ 7039.691224] Key type ._llcrypt unregistered