[ 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 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-2.fc40 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 467387614 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 0x000f53f0-0x000f53ff] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 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.001011] APIC: Switch to symmetric I/O mode setup [ 0.002392] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004012] kvm-guest: setup PV IPIs [ 0.007544] ..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.008028] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009013] pid_max: default: 32768 minimum: 301 [ 0.010151] LSM: Security Framework initializing [ 0.011067] Yama: becoming mindful. [ 0.013004] SELinux: Initializing. [ 0.014000] *** VALIDATE selinux *** [ 0.021031] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025781] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026146] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027116] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028116] *** VALIDATE tmpfs *** [ 0.029465] *** VALIDATE proc *** [ 0.031033] *** VALIDATE cgroup *** [ 0.032010] *** VALIDATE cgroup2 *** [ 0.033252] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034150] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036027] Spectre V2 : User space: Vulnerable [ 0.037012] Speculative Store Bypass: Vulnerable [ 0.040418] debug: unmapping init [mem 0xffffffff90e59000-0xffffffff90e60fff] [ 0.042920] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.043732] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.044023] ... version: 2 [ 0.045014] ... bit width: 48 [ 0.046011] ... generic registers: 4 [ 0.047015] ... value mask: 0000ffffffffffff [ 0.048017] ... max period: 00007fffffffffff [ 0.049015] ... fixed-purpose events: 3 [ 0.050012] ... event mask: 000000070000000f [ 0.051284] rcu: Hierarchical SRCU implementation. [ 0.053452] smp: Bringing up secondary CPUs ... [ 0.054415] x86: Booting SMP configuration: [ 0.055020] .... node #0, CPUs: #1 #2 #3 [ 0.058080] smp: Brought up 1 node, 4 CPUs [ 0.060013] smpboot: Max logical packages: 1 [ 0.060917] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.271151] node 0 deferred pages initialised in 209ms [ 0.275009] devtmpfs: initialized [ 0.276248] x86/mm: Memory block size: 128MB [ 0.278738] gcov: version magic: 0x41383552 [ 0.279685] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.283086] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.285297] pinctrl core: initialized pinctrl subsystem [ 0.287179] [ 0.287752] ************************************************************* [ 0.290014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.292010] ** ** [ 0.293010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.295013] ** ** [ 0.297011] ** This means that this kernel is built to expose internal ** [ 0.300012] ** IOMMU data structures, which may compromise security on ** [ 0.302011] ** your system. ** [ 0.304013] ** ** [ 0.306011] ** If you see this message and you are not debugging the ** [ 0.308014] ** kernel, report this immediately to your vendor! ** [ 0.310011] ** ** [ 0.312012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.313011] ************************************************************* [ 0.316657] NET: Registered protocol family 16 [ 0.318420] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.320063] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.323067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.326459] cpuidle: using governor menu [ 0.327604] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.329352] PCI: Using configuration type 1 for base access [ 0.331128] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.341148] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.343023] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.347091] cryptd: max_cpu_qlen set to 1000 [ 0.349295] ACPI: Added _OSI(Module Device) [ 0.350035] ACPI: Added _OSI(Processor Device) [ 0.351000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.352018] ACPI: Added _OSI(Processor Aggregator Device) [ 0.357573] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.364123] ACPI: Interpreter enabled [ 0.365086] ACPI: PM: (supports S0 S3 S4 S5) [ 0.367022] ACPI: Using IOAPIC for interrupt routing [ 0.367966] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.370317] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.378935] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.380039] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.383020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.385075] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.390200] acpiphp: Slot [2] registered [ 0.391112] acpiphp: Slot [5] registered [ 0.393110] acpiphp: Slot [6] registered [ 0.394108] acpiphp: Slot [7] registered [ 0.395103] acpiphp: Slot [8] registered [ 0.397109] acpiphp: Slot [9] registered [ 0.398105] acpiphp: Slot [10] registered [ 0.400138] acpiphp: Slot [3] registered [ 0.401104] acpiphp: Slot [4] registered [ 0.402099] acpiphp: Slot [11] registered [ 0.404106] acpiphp: Slot [12] registered [ 0.405112] acpiphp: Slot [13] registered [ 0.406124] acpiphp: Slot [14] registered [ 0.408097] acpiphp: Slot [15] registered [ 0.409108] acpiphp: Slot [16] registered [ 0.411108] acpiphp: Slot [17] registered [ 0.412095] acpiphp: Slot [18] registered [ 0.413083] acpiphp: Slot [19] registered [ 0.415089] acpiphp: Slot [20] registered [ 0.416121] acpiphp: Slot [21] registered [ 0.418111] acpiphp: Slot [22] registered [ 0.419127] acpiphp: Slot [23] registered [ 0.421127] acpiphp: Slot [24] registered [ 0.423139] acpiphp: Slot [25] registered [ 0.424160] acpiphp: Slot [26] registered [ 0.426134] acpiphp: Slot [27] registered [ 0.427137] acpiphp: Slot [28] registered [ 0.428083] acpiphp: Slot [29] registered [ 0.430099] acpiphp: Slot [30] registered [ 0.431091] acpiphp: Slot [31] registered [ 0.432060] PCI host bridge to bus 0000:00 [ 0.434018] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.435020] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.437022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.440023] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.442022] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 0.445028] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.447320] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.450111] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.453340] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.463015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.467431] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.469015] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.470014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.473015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.475603] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.478072] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.482052] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.484639] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.489015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.502015] pci 0000:00:02.0: reg 0x20: [mem 0x380000000000-0x380000003fff 64bit pref] [ 0.508015] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.513816] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.520015] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.526019] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.540023] pci 0000:00:05.0: reg 0x20: [mem 0x380000004000-0x380000007fff 64bit pref] [ 0.549214] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.556015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.563016] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.580021] pci 0000:00:06.0: reg 0x20: [mem 0x380000008000-0x38000000bfff 64bit pref] [ 0.589285] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.595013] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.600017] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.614020] pci 0000:00:07.0: reg 0x20: [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 0.622198] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.626015] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.631014] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.645026] pci 0000:00:08.0: reg 0x20: [mem 0x380000010000-0x380000013fff 64bit pref] [ 0.654216] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.662024] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.668020] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.685026] pci 0000:00:09.0: reg 0x20: [mem 0x380000014000-0x380000017fff 64bit pref] [ 0.695731] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.702021] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.708020] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.723030] pci 0000:00:0a.0: reg 0x20: [mem 0x380000018000-0x38000001bfff 64bit pref] [ 0.735037] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.737432] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.739374] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.741396] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.743282] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.748248] iommu: Default domain type: Passthrough [ 0.749401] SCSI subsystem initialized [ 0.750000] ACPI: bus type USB registered [ 0.752150] usbcore: registered new interface driver usbfs [ 0.754089] usbcore: registered new interface driver hub [ 0.755111] usbcore: registered new device driver usb [ 0.757203] pps_core: LinuxPPS API ver. 1 registered [ 0.758011] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.761083] PTP clock support registered [ 0.763189] EDAC MC: Ver: 3.0.0 [ 0.769219] PCI: Using ACPI for IRQ routing [ 0.772438] NetLabel: Initializing [ 0.774017] NetLabel: domain hash size = 128 [ 0.775013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.778126] NetLabel: unlabeled traffic allowed by default [ 0.781123] vgaarb: loaded [ 0.783227] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.784013] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.787359] clocksource: Switched to clocksource kvm-clock [ 0.897258] VFS: Disk quotas dquot_6.6.0 [ 0.898887] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.901485] *** VALIDATE ramfs *** [ 0.902917] *** VALIDATE hugetlbfs *** [ 0.904342] pnp: PnP ACPI init [ 0.906692] pnp: PnP ACPI: found 6 devices [ 0.925832] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.929495] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.932030] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.934354] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.936824] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.939401] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 0.942617] NET: Registered protocol family 2 [ 0.945268] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.950421] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.953417] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.959536] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.963115] TCP: Hash tables configured (established 65536 bind 65536) [ 0.966342] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.969649] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.972367] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.975307] NET: Registered protocol family 1 [ 0.980897] RPC: Registered named UNIX socket transport module. [ 0.982954] RPC: Registered udp transport module. [ 0.984760] RPC: Registered tcp transport module. [ 0.986822] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.988807] NET: Registered protocol family 44 [ 0.990514] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.992704] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.995014] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.997352] PCI: CLS 0 bytes, default 64 [ 0.999156] Unpacking initramfs... [ 2.445525] debug: unmapping init [mem 0xffff8fbbfcc54000-0xffff8fbbfffbffff] [ 2.451902] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.454223] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.458457] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.959986] Initialise system trusted keyrings [ 2.961925] Key type blacklist registered [ 2.964106] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.975478] zbud: loaded [ 2.978630] *** VALIDATE nfs *** [ 2.979889] *** VALIDATE nfs4 *** [ 2.981427] pstore: using deflate compression [ 2.984687] Platform Keyring initialized [ 3.084218] NET: Registered protocol family 38 [ 3.086031] Key type asymmetric registered [ 3.087436] Asymmetric key parser 'x509' registered [ 3.089545] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.092615] io scheduler mq-deadline registered [ 3.094364] io scheduler kyber registered [ 3.095905] io scheduler bfq registered [ 3.097974] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.101039] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.104120] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.107215] ACPI: Power Button [PWRF] [ 3.200600] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.292530] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.485803] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.579404] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.777440] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.810223] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.841935] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.848834] Non-volatile memory driver v1.3 [ 3.852079] Linux agpgart interface v0.103 [ 3.894164] virtio_blk virtio1: [vda] 67976 512-byte logical blocks (34.8 MB/33.2 MiB) [ 3.898392] vda: detected capacity change from 0 to 34803712 [ 3.916311] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.919718] vdb: detected capacity change from 0 to 1073741824 [ 3.935353] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.938831] vdc: detected capacity change from 0 to 2621440000 [ 3.957726] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.960568] vdd: detected capacity change from 0 to 2621440000 [ 3.974901] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.977616] vde: detected capacity change from 0 to 4294967296 [ 3.995873] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.998964] vdf: detected capacity change from 0 to 4294967296 [ 4.005720] libphy: Fixed MDIO Bus: probed [ 4.013312] usbcore: registered new interface driver usbserial_generic [ 4.015877] usbserial: USB Serial support registered for generic [ 4.018322] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.022782] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.024927] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.027701] mousedev: PS/2 mouse device common for all mice [ 4.030547] rtc_cmos 00:05: RTC can wake from S4 [ 4.033787] rtc_cmos 00:05: registered as rtc0 [ 4.035727] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.039039] intel_pstate: CPU model not supported [ 4.040404] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.046446] hid: raw HID events driver (C) Jiri Kosina [ 4.049577] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.050344] usbcore: registered new interface driver usbhid [ 4.055030] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.055984] usbhid: USB HID core driver [ 4.061752] drop_monitor: Initializing network drop monitor service [ 4.065595] Initializing XFRM netlink socket [ 4.067782] NET: Registered protocol family 10 [ 4.071073] Segment Routing with IPv6 [ 4.072252] NET: Registered protocol family 17 [ 4.074143] mpls_gso: MPLS GSO support [ 4.080760] RAS: Correctable Errors collector initialized. [ 4.083088] AVX version of gcm_enc/dec engaged. [ 4.084832] AES CTR mode by8 optimization enabled [ 4.160573] sched_clock: Marking stable (4160549176, 0)->(5053560705, -893011529) [ 4.164203] registered taskstats version 1 [ 4.165889] Loading compiled-in X.509 certificates [ 4.167619] zswap: loaded using pool lzo/zbud [ 4.194416] Key type big_key registered [ 4.207541] Key type encrypted registered [ 4.210195] ima: No TPM chip found, activating TPM-bypass! [ 4.212657] ima: Allocated hash algorithm: sha1 [ 4.214575] ima: No architecture policies found [ 4.216313] evm: Initialising EVM extended attributes: [ 4.218253] evm: security.selinux [ 4.219473] evm: security.ima [ 4.220699] evm: security.capability [ 4.222081] evm: HMAC attrs: 0x1 [ 4.224533] rtc_cmos 00:05: setting system clock to 2025-10-23 16:56:26 UTC (1761238586) [ 4.230352] debug: unmapping init [mem 0xffffffff91e03000-0xffffffff91ffffff] [ 4.233523] debug: unmapping init [mem 0xffffffff90b82000-0xffffffff90e58fff] [ 4.241138] Write protecting the kernel read-only data: 28672k [ 4.244221] debug: unmapping init [mem 0xffffffff8f203000-0xffffffff8f3fffff] [ 4.247212] debug: unmapping init [mem 0xffffffff8fb14000-0xffffffff8fbfffff] [ 4.281946] 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) [ 4.290173] systemd[1]: Detected virtualization kvm. [ 4.292252] systemd[1]: Detected architecture x86-64. [ 4.293783] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.324889] systemd[1]: No hostname configured. [ 4.326595] systemd[1]: Set hostname to . [ 4.328858] random: systemd: uninitialized urandom read (16 bytes read) [ 4.331502] systemd[1]: Initializing machine ID from random generator. [ 4.367644] random: ln: uninitialized urandom read (6 bytes read) [ 4.487994] random: systemd: uninitialized urandom read (16 bytes read) [ 4.491766] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 4.497322] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 4.502831] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Local File Systems. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... Starting Journal Service... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... [ OK ] Reached target Sockets. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Timers. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 5.177318] device-mapper: uevent: version 1.0.3 [ 5.179900] 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... [ 5.506407] random: fast init done [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 6.021461] virtio_net virtio0 ens2: renamed from eth0 [ 6.073185] scsi host0: ata_piix [ 6.086799] scsi host1: ata_piix [ 6.088201] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 6.090287] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.900146] dracut-initqueue[582]: RTNETLINK answers: File exists [ 10.726960] random: crng init done [ 10.728450] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 11.273650] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ 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 Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.480378] printk: systemd: 25 output lines suppressed due to ratelimiting [ 12.737587] SELinux: Disabled at runtime. [ 12.792670] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.802377] systemd[1]: Detected virtualization kvm. [ 12.804843] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.305966] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.309254] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.314248] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.320481] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.324228] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.332382] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.340326] systemd[1]: Mounting Huge Pages File System... Mounting Huge Pages File System... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on RPCbind Server Activation Socket. Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Switch Root. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting POSIX Message Queue File System... [ OK ] Stopped target Initrd File Systems. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Stopped target Initrd Root File System. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice User and Session Slice. [ OK [[ 13.396533] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS 0m] Reached target Slices. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. Starting Create list of required st…ce nodes for the current kernel... Mounting Kernel Debug File System... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-getty.slice. Starting Apply Kernel Variables... [ OK ] Reached target rpc_pipefs.target. Starting Remount Root and Kernel File Systems... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.838850] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 14.220985] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 14.239458] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.433732] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.447280] EDAC sbridge: Ver: 1.1.2 [ 15.967457] Key type dns_resolver registered [ 16.275367] NFS: Registering the id_resolver key type [ 16.277210] Key type id_resolver registered [ 16.279189] Key type id_legacy registered [ 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 update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started Login Service. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... 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 Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ 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 System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg108-server login: [ 30.864604] spl: loading out-of-tree module taints kernel. [ 33.510794] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 38.747978] alg: No test for adler32 (adler32-zlib) [ 39.499544] Key type ._llcrypt registered [ 39.501072] Key type .llcrypt registered [ 39.559537] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_hostid [ 53.350000] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing load_modules_local [ 54.284168] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 54.910980] Lustre: Lustre: Build Version: 2.15.7_8_g45c9f5a [ 55.639309] LNet: Added LNI 192.168.201.108@tcp [8/256/0/180] [ 55.645771] LNet: Accept secure, port 988 [ 57.392713] Key type lgssc registered [ 58.700909] Lustre: Echo OBD driver; http://www.lustre.org/ [ 66.078433] vdc: vdc1 vdc9 [ 73.926449] vde: vde1 vde9 [ 82.556203] vdf: vdf1 vdf9 [ 94.829662] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing load_modules_local [ 102.535193] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 102.798059] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space: rc = -61 [ 102.884534] Lustre: lustre-MDT0000: new disk, initializing [ 103.229471] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 103.282322] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 107.250273] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 114.264171] Lustre: lustre-OST0000: new disk, initializing [ 114.276876] Lustre: srv-lustre-OST0000: No data found on store. Initialize space: rc = -61 [ 114.280189] Lustre: Skipped 1 previous similar message [ 114.347794] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 118.219197] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 125.708214] LustreError: 137-5: lustre-OST0001_UUID: 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. [ 125.776695] Lustre: lustre-OST0001: new disk, initializing [ 125.779627] Lustre: srv-lustre-OST0001: No data found on store. Initialize space: rc = -61 [ 125.872111] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 128.327075] hrtimer: interrupt took 5063426 ns [ 129.364535] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 138.283255] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 143.099419] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 150.867813] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing check_logdir /tmp/testlogs/ [ 154.620747] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing yml_node [ 157.218376] Lustre: DEBUG MARKER: Client: 2.15.7.8 [ 158.709455] Lustre: DEBUG MARKER: MDS: 2.15.7.8 [ 160.382080] Lustre: DEBUG MARKER: OSS: 2.15.7.8 [ 161.348100] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Thu Oct 23 12:59:02 EDT 2025 [ 167.008467] Lustre: DEBUG MARKER: excepting tests: 59 [ 171.429504] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing check_config_client /mnt/lustre [ 184.229572] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 186.514114] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 189.113601] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 190.442564] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 12:59:31 (1761238771) [ 192.720590] LustreError: 10690:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 193.426088] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 194.843405] Lustre: Failing over lustre-MDT0000 [ 195.163593] Lustre: server umount lustre-MDT0000 complete [ 203.744388] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761238779/real 1761238779] req@00000000c78e31e0 x1846792565052544/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761238786 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 203.745798] 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 [ 203.764092] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 203.801140] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 208.864157] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761238784/real 1761238784] req@000000003cad477a x1846792565052800/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761238791 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 208.882595] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 221.156830] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c77548e8a to 0x1e87481c77549330 [ 221.166255] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 221.500226] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 224.122953] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 235.503680] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 235.575971] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 237.030138] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to (at 0@lo) [ 240.169764] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 241.297681] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 247.200501] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 13:00:28 (1761238828) [ 248.576459] Lustre: Failing over lustre-OST0000 [ 248.646807] Lustre: server umount lustre-OST0000 complete [ 250.899001] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 251.362697] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 251.366796] 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 [ 251.372563] Lustre: Skipped 1 previous similar message [ 252.386327] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 252.393014] LustreError: Skipped 1 previous similar message [ 255.982544] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 261.108325] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 261.126296] LustreError: Skipped 1 previous similar message [ 264.759119] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 266.226240] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 266.552904] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 266.557208] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.201.108@tcp (at 0@lo) [ 266.568488] Lustre: Skipped 1 previous similar message [ 266.581962] Lustre: lustre-OST0000: deleting orphan objects from 0x0:34 to 0x0:65 [ 267.739210] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 274.486231] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 275.558052] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 283.277572] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 13:01:04 (1761238864) [ 285.600495] LustreError: 13754:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 286.306183] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 287.948572] Lustre: Failing over lustre-MDT0000 [ 288.168847] Lustre: server umount lustre-MDT0000 complete [ 297.440154] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761238872/real 1761238872] req@00000000d5ddf7ee x1846792565066816/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761238879 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 297.444499] 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 [ 297.478701] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 297.515634] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 302.624457] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761238877/real 1761238877] req@00000000f9896a03 x1846792565067072/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761238884 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 302.652591] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 313.828488] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c77549330 to 0x1e87481c77549c91 [ 313.846666] Lustre: MGC192.168.201.108@tcp: Connection restored to 192.168.201.108@tcp (at 0@lo) [ 314.345106] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 319.076378] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 320.963296] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 320.967863] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 326.126254] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:53 [ 330.533040] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 331.246372] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:48 [ 336.366923] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:43 [ 341.492506] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:38 [ 351.725545] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:28 [ 351.736204] Lustre: Skipped 1 previous similar message [ 372.208128] Lustre: lustre-MDT0000: Denying connection for new client ef97bdb9-042e-41d5-8ede-b83233a3a8e7 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:07 [ 372.217610] Lustre: Skipped 3 previous similar messages [ 380.000555] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 380.003550] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 380.040246] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 380.068664] Lustre: lustre-OST0000: deleting orphan objects from 0x0:76 to 0x0:97 [ 380.070973] Lustre: lustre-OST0001: deleting orphan objects from 0x0:44 to 0x0:65 [ 390.112518] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 13:02:51 (1761238971) [ 392.746151] LustreError: 15192:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 393.706796] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 395.374862] Lustre: Failing over lustre-MDT0000 [ 395.755818] Lustre: server umount lustre-MDT0000 complete [ 404.384104] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761238979/real 1761238979] req@000000009cfe79bb x1846792565079232/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761238986 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 404.400567] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 404.408932] 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 [ 404.419612] Lustre: Skipped 1 previous similar message [ 404.448192] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 420.841802] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c77549c91 to 0x1e87481c7754a026 [ 420.857958] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 420.877699] Lustre: Skipped 1 previous similar message [ 421.200683] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 424.906525] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 426.847427] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 426.851681] Lustre: lustre-MDT0000: Denying connection for new client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 426.861890] Lustre: Skipped 1 previous similar message [ 437.414046] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 486.000179] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 486.002675] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 486.074905] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 486.152687] Lustre: lustre-OST0001: deleting orphan objects from 0x0:44 to 0x0:97 [ 486.153797] Lustre: lustre-OST0000: deleting orphan objects from 0x0:76 to 0x0:129 [ 496.236468] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 13:04:37 (1761239077) [ 498.702729] LustreError: 16622:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 499.438751] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 500.982182] Lustre: Failing over lustre-MDT0000 [ 501.324320] Lustre: server umount lustre-MDT0000 complete [ 511.328494] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239086/real 1761239086] req@00000000c56aba46 x1846792565090432/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761239093 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 511.342945] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 511.346353] 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 [ 511.352233] Lustre: Skipped 1 previous similar message [ 511.458076] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 527.842994] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754a026 to 0x1e87481c7754a424 [ 527.858946] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 527.869186] Lustre: Skipped 1 previous similar message [ 528.347952] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 529.630124] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 529.751436] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 529.787661] Lustre: lustre-OST0001: deleting orphan objects from 0x0:44 to 0x0:129 [ 529.789236] Lustre: lustre-OST0000: deleting orphan objects from 0x0:76 to 0x0:161 [ 531.853100] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 540.309774] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 541.581971] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 547.613645] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 13:05:29 (1761239129) [ 549.612758] LustreError: 18272:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 550.288184] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 551.538660] Lustre: Failing over lustre-MDT0000 [ 551.824636] Lustre: server umount lustre-MDT0000 complete [ 562.016449] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239137/real 1761239137] req@000000005409166e x1846792565097472/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761239144 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 562.041762] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 562.047828] 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 [ 562.053328] Lustre: Skipped 1 previous similar message [ 562.058903] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 568.161489] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754a424 to 0x1e87481c7754a892 [ 571.666950] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 578.551315] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 578.708920] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 578.752064] Lustre: lustre-OST0000: deleting orphan objects from 0x0:76 to 0x0:193 [ 578.754612] Lustre: lustre-OST0001: deleting orphan objects from 0x0:131 to 0x0:161 [ 583.762939] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 585.062309] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 592.447832] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 13:06:13 (1761239173) [ 595.052661] LustreError: 19920:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 595.683617] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 597.565604] Lustre: Failing over lustre-MDT0000 [ 597.831098] Lustre: server umount lustre-MDT0000 complete [ 607.200155] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239182/real 1761239182] req@000000007b01e492 x1846792565105024/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761239189 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 607.203699] 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 [ 607.219458] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 607.219574] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 607.245329] Lustre: Skipped 2 previous similar messages [ 624.623527] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754a892 to 0x1e87481c7754ad46 [ 624.638635] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 624.645953] Lustre: Skipped 5 previous similar messages [ 625.204990] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 625.212222] Lustre: Skipped 1 previous similar message [ 625.301357] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 629.281357] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 638.972911] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 639.083536] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 639.120764] Lustre: lustre-OST0001: deleting orphan objects from 0x0:131 to 0x0:193 [ 639.121325] Lustre: lustre-OST0000: deleting orphan objects from 0x0:195 to 0x0:225 [ 644.555783] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 646.071465] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 653.680577] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 13:07:14 (1761239234) [ 656.160456] LustreError: 21571:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 656.839734] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 658.314306] Lustre: Failing over lustre-MDT0000 [ 658.584836] Lustre: server umount lustre-MDT0000 complete [ 668.000218] 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 [ 669.024329] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 673.188117] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239248/real 1761239248] req@00000000e8373395 x1846792565113216/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761239255 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 673.198726] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 675.104857] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754ad46 to 0x1e87481c7754b1c9 [ 675.425477] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 677.950982] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 682.997077] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 683.082182] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 683.139878] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:225 [ 683.142897] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:257 [ 687.606226] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 688.968904] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 695.573284] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 13:07:56 (1761239276) [ 698.063621] LustreError: 23216:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 698.845456] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 713.184568] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 719.264690] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754b1c9 to 0x1e87481c7754b645 [ 719.668221] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 722.632789] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 727.165711] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:289 [ 727.167577] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:257 [ 731.730300] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 732.917082] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 739.372784] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 13:08:40 (1761239320) [ 740.101925] Lustre: *** cfs_fail_loc=13b, val=315*** [ 740.103953] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 740.105780] LustreError: 23827:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@0000000032b32262 x1846792552502912/t38654705666(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:254/0 lens 392/456 e 0 to 0 dl 1761239339 ref 1 fl Interpret:/0/0 rc 0/0 job:'openfile.0' [ 744.422074] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 746.076660] Lustre: Failing over lustre-MDT0000 [ 746.078657] Lustre: Skipped 1 previous similar message [ 746.387400] Lustre: server umount lustre-MDT0000 complete [ 746.391263] Lustre: Skipped 1 previous similar message [ 753.574685] 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 [ 753.592961] Lustre: Skipped 3 previous similar messages [ 775.075924] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 775.079918] Lustre: Skipped 8 previous similar messages [ 775.410248] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 775.412896] Lustre: Skipped 2 previous similar messages [ 775.472680] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 778.199207] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 787.443574] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 787.450222] Lustre: Skipped 1 previous similar message [ 787.502763] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 787.510753] Lustre: Skipped 1 previous similar message [ 787.531551] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:321 [ 787.533816] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:289 [ 787.542375] Lustre: 25524:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000a3e2eb61 x1846792552502912/t38654705666(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:301/0 lens 392/456 e 0 to 0 dl 1761239386 ref 1 fl Interpret:/2/0 rc 0/0 job:'openfile.0' [ 791.364481] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 792.528492] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 799.057928] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 13:09:40 (1761239380) [ 801.496155] LustreError: 26556:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 801.500027] LustreError: 26556:0:(osd_handler.c:698:osd_ro()) Skipped 1 previous similar message [ 802.248432] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 813.475726] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239388/real 1761239388] req@00000000b7319fb7 x1846792565134336/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761239395 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 813.505228] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 813.511804] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 813.516375] LustreError: Skipped 1 previous similar message [ 829.928435] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754baa5 to 0x1e87481c7754bed4 [ 829.947943] Lustre: Skipped 1 previous similar message [ 830.303217] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 832.656893] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:353 [ 832.686120] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:321 [ 834.054367] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 842.514421] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 844.143160] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 851.569533] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 13:10:32 (1761239432) [ 854.345136] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 855.135291] Lustre: *** cfs_fail_loc=114, val=0*** [ 875.945776] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 879.304292] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 881.726326] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:385 [ 881.727461] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:353 [ 887.213948] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 888.781904] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 895.737338] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 13:11:17 (1761239477) [ 899.158676] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 899.970080] Lustre: *** cfs_fail_loc=128, val=0*** [ 902.383646] Lustre: Failing over lustre-MDT0000 [ 902.385135] Lustre: Skipped 2 previous similar messages [ 902.699516] Lustre: server umount lustre-MDT0000 complete [ 902.701251] Lustre: Skipped 2 previous similar messages [ 913.760557] 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 [ 913.766030] Lustre: Skipped 5 previous similar messages [ 920.466153] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 920.558420] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 920.562757] Lustre: Skipped 2 previous similar messages [ 920.701856] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 920.716962] Lustre: Skipped 2 previous similar messages [ 920.752559] Lustre: lustre-OST0000: deleting orphan objects from 0x0:227 to 0x0:417 [ 920.756114] Lustre: lustre-OST0001: deleting orphan objects from 0x0:195 to 0x0:385 [ 923.983565] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 933.445900] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 934.915406] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 941.927372] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 13:12:03 (1761239523) [ 944.585209] LustreError: 31648:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 944.590917] LustreError: 31648:0:(osd_handler.c:698:osd_ro()) Skipped 2 previous similar messages [ 945.377732] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 958.432363] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 958.441256] LustreError: Skipped 2 previous similar messages [ 964.580993] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7754c724 to 0x1e87481c7754ccc6 [ 964.592635] Lustre: Skipped 2 previous similar messages [ 965.002522] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 968.879678] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 976.223041] Lustre: lustre-OST0000: deleting orphan objects from 0x0:423 to 0x0:449 [ 976.225691] Lustre: lustre-OST0001: deleting orphan objects from 0x0:391 to 0x0:417 [ 981.562717] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 982.909488] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 990.578272] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 13:12:51 (1761239571) [ 993.568728] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1021.493620] Lustre: lustre-OST0000: deleting orphan objects from 0x0:455 to 0x0:481 [ 1021.493638] Lustre: lustre-OST0001: deleting orphan objects from 0x0:423 to 0x0:449 [ 1023.749545] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1030.309147] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1031.449627] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1036.263647] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 1036.268874] Lustre: Skipped 15 previous similar messages [ 1037.930995] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 13:13:39 (1761239619) [ 1040.898214] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1063.945377] LustreError: 137-5: lustre-MDT0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1063.961061] LustreError: Skipped 1 previous similar message [ 1064.219249] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1064.223790] Lustre: Skipped 5 previous similar messages [ 1064.296252] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1064.299399] Lustre: Skipped 1 previous similar message [ 1067.020618] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1068.120199] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:577 [ 1068.120582] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:609 [ 1074.363863] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1075.559623] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1094.624597] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761239633/real 1761239633] req@000000005ef90e13 x1846792565172352/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761239676 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 1094.644891] Lustre: 3035:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 30 previous similar messages [ 1096.222746] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 13:14:37 (1761239677) [ 1099.152538] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1131.602391] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:641 [ 1131.602878] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:609 [ 1133.269781] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1141.394083] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1142.938632] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1152.586880] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 13:15:33 (1761239733) [ 1156.167841] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1185.038314] 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 [ 1185.050968] Lustre: Skipped 10 previous similar messages [ 1185.832925] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1185.841099] Lustre: Skipped 4 previous similar messages [ 1185.954901] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1185.961245] Lustre: Skipped 4 previous similar messages [ 1186.009487] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:673 [ 1186.009563] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:641 [ 1188.948704] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1197.155049] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1198.526546] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1205.415781] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 13:16:26 (1761239786) [ 1208.133947] LustreError: 39916:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1208.138164] LustreError: 39916:0:(osd_handler.c:698:osd_ro()) Skipped 4 previous similar messages [ 1208.868651] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1210.629858] Lustre: Failing over lustre-MDT0000 [ 1210.641480] Lustre: Skipped 5 previous similar messages [ 1210.848849] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1211.030823] Lustre: server umount lustre-MDT0000 complete [ 1211.033675] Lustre: Skipped 5 previous similar messages [ 1223.140059] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1223.143737] LustreError: Skipped 4 previous similar messages [ 1229.283426] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7755682b to 0x1e87481c77556c84 [ 1229.289276] Lustre: Skipped 4 previous similar messages [ 1229.874774] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1229.891295] Lustre: Skipped 2 previous similar messages [ 1232.120472] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:673 [ 1232.121652] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:705 [ 1234.682467] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1244.817626] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1246.195644] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1255.189790] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 13:17:16 (1761239836) [ 1258.832559] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1287.908189] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:705 [ 1287.909173] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:737 [ 1291.987874] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1300.701380] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1302.705655] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1311.335933] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 13:18:12 (1761239892) [ 1314.996278] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1343.955341] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:737 [ 1343.956031] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:769 [ 1345.912471] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1354.111107] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1355.829591] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1363.739468] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 13:19:04 (1761239944) [ 1367.808646] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1399.275363] Lustre: lustre-OST0001: deleting orphan objects from 0x0:560 to 0x0:769 [ 1399.277263] Lustre: lustre-OST0000: deleting orphan objects from 0x0:592 to 0x0:801 [ 1401.693378] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1410.595328] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1412.382424] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1419.601256] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 13:20:00 (1761240000) [ 1423.017555] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1446.567657] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1446.645147] Lustre: lustre-OST0000: deleting orphan objects from 0x0:803 to 0x0:833 [ 1446.645870] Lustre: lustre-OST0001: deleting orphan objects from 0x0:771 to 0x0:801 [ 1454.902086] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1456.310580] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1463.172426] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 13:20:44 (1761240044) [ 1466.589200] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1468.392988] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1468.395498] Lustre: Skipped 2 previous similar messages [ 1497.549599] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1497.559835] Lustre: Skipped 4 previous similar messages [ 1497.960051] Lustre: lustre-OST0000: deleting orphan objects from 0x0:803 to 0x0:865 [ 1497.963139] Lustre: lustre-OST0001: deleting orphan objects from 0x0:771 to 0x0:833 [ 1501.672559] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1511.311578] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1512.903716] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1520.396073] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 13:21:41 (1761240101) [ 1523.853141] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1549.793975] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 1549.795956] Lustre: Skipped 28 previous similar messages [ 1550.562907] Lustre: lustre-OST0000: deleting orphan objects from 0x0:803 to 0x0:897 [ 1554.350159] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1563.061856] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1564.776404] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1571.622375] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 13:22:32 (1761240152) [ 1574.734717] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1594.908989] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1594.911924] Lustre: Skipped 9 previous similar messages [ 1598.536344] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1600.184399] Lustre: lustre-OST0000: deleting orphan objects from 0x0:899 to 0x0:929 [ 1600.202081] Lustre: lustre-OST0001: deleting orphan objects from 0x0:835 to 0x0:865 [ 1606.589838] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1607.593525] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1613.831517] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 13:23:15 (1761240195) [ 1617.134647] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1622.496255] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761240163/real 1761240163] req@00000000b8ad00a7 x1846792565278208/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761240204 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 1622.512670] Lustre: 3033:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 118 previous similar messages [ 1645.829572] Lustre: lustre-OST0001: deleting orphan objects from 0x0:867 to 0x0:897 [ 1645.835209] Lustre: lustre-OST0000: deleting orphan objects from 0x0:931 to 0x0:961 [ 1648.254891] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1656.436414] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1657.934371] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1664.840394] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 13:24:06 (1761240246) [ 1667.850609] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1696.443297] Lustre: lustre-OST0000: deleting orphan objects from 0x0:963 to 0x0:993 [ 1696.443964] Lustre: lustre-OST0001: deleting orphan objects from 0x0:867 to 0x0:929 [ 1699.311950] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1708.790218] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1710.120611] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1717.908580] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 13:24:59 (1761240299) [ 1720.665724] LustreError: 56307:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1720.676086] LustreError: 56307:0:(osd_handler.c:698:osd_ro()) Skipped 9 previous similar messages [ 1721.604193] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1723.111313] Lustre: Failing over lustre-MDT0000 [ 1723.113618] Lustre: Skipped 9 previous similar messages [ 1723.426941] Lustre: server umount lustre-MDT0000 complete [ 1723.428887] Lustre: Skipped 9 previous similar messages [ 1750.498573] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7755972c to 0x1e87481c77559bee [ 1750.511124] Lustre: Skipped 9 previous similar messages [ 1752.058672] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1752.072977] Lustre: Skipped 10 previous similar messages [ 1752.233707] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1752.249192] Lustre: Skipped 10 previous similar messages [ 1752.285537] Lustre: lustre-OST0000: deleting orphan objects from 0x0:963 to 0x0:1025 [ 1752.285924] Lustre: lustre-OST0001: deleting orphan objects from 0x0:931 to 0x0:961 [ 1754.601753] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1756.135501] 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 [ 1756.146298] Lustre: Skipped 21 previous similar messages [ 1763.177581] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1764.646608] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1771.675268] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 13:25:52 (1761240352) [ 1774.982976] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1776.610948] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1776.617330] Lustre: Skipped 1 previous similar message [ 1788.832550] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1788.855546] LustreError: Skipped 10 previous similar messages [ 1796.304861] Lustre: lustre-OST0001: deleting orphan objects from 0x0:963 to 0x0:993 [ 1796.311468] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1027 to 0x0:1057 [ 1799.674670] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1810.530808] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1812.225274] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1819.982593] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 13:26:41 (1761240401) [ 1823.200855] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1852.155022] Lustre: lustre-OST0001: deleting orphan objects from 0x0:995 to 0x0:1025 [ 1855.571929] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1863.968469] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1865.383233] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1873.354369] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 13:27:34 (1761240454) [ 1876.847845] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1907.415273] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1059 to 0x0:1089 [ 1907.421532] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1027 to 0x0:1057 [ 1911.143769] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1919.780780] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1921.048549] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1927.566265] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 13:28:28 (1761240508) [ 1930.540142] Lustre: 62847:0:(genops.c:1710:obd_export_evict_by_uuid()) lustre-MDT0000: evicting d54afc0b-13e8-42b0-82a0-1a9026c309d0 at adminstrative request [ 1963.844653] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1091 to 0x0:1121 [ 1963.845255] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1027 to 0x0:1089 [ 1966.670221] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 1975.885074] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1977.310588] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1981.906467] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1994.596413] Lustre: DEBUG MARKER: before 6144, after 6144 [ 2000.382317] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 13:29:41 (1761240581) [ 2001.456230] Lustre: 64872:0:(genops.c:1710:obd_export_evict_by_uuid()) lustre-MDT0000: evicting d54afc0b-13e8-42b0-82a0-1a9026c309d0 at adminstrative request [ 2011.929809] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 13:29:52 (1761240592) [ 2015.128673] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2043.304435] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2043.307133] Lustre: Skipped 9 previous similar messages [ 2043.622546] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1091 to 0x0:1121 [ 2046.982364] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2057.182406] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2058.835283] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2068.926527] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 13:30:49 (1761240649) [ 2073.088281] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2104.608984] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1124 to 0x0:1153 [ 2104.611279] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1124 to 0x0:1153 [ 2109.147325] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2119.462507] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2121.606965] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2130.760297] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 13:31:51 (1761240711) [ 2135.259812] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2163.688393] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 2163.690908] Lustre: Skipped 32 previous similar messages [ 2164.874996] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1155 to 0x0:1185 [ 2168.498791] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2179.609518] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2181.569639] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2190.375298] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 13:32:51 (1761240771) [ 2193.832446] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2214.071319] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2214.074497] Lustre: Skipped 10 previous similar messages [ 2217.585453] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1188 to 0x0:1217 [ 2217.586717] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1155 to 0x0:1185 [ 2218.247052] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2227.828803] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2229.625855] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2237.312891] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 13:33:38 (1761240818) [ 2241.504111] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761240782/real 1761240782] req@000000002974818c x1846792565365760/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761240823 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 2241.546256] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 155 previous similar messages [ 2241.630522] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2271.945781] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1219 to 0x0:1249 [ 2271.949063] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1155 to 0x0:1217 [ 2273.731823] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2284.695569] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2286.496340] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2295.017954] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 13:34:36 (1761240876) [ 2298.966572] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2330.786217] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1251 to 0x0:1281 [ 2330.786381] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1219 to 0x0:1249 [ 2333.005049] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2342.197250] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2343.911859] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2352.057653] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 13:35:33 (1761240933) [ 2354.596091] LustreError: 75066:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2354.600024] LustreError: 75066:0:(osd_handler.c:698:osd_ro()) Skipped 9 previous similar messages [ 2355.360379] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2357.120053] Lustre: Failing over lustre-MDT0000 [ 2357.122641] Lustre: Skipped 10 previous similar messages [ 2357.563561] Lustre: server umount lustre-MDT0000 complete [ 2357.568355] Lustre: Skipped 10 previous similar messages [ 2383.844974] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7755ca86 to 0x1e87481c7755cfbf [ 2383.863388] Lustre: Skipped 10 previous similar messages [ 2384.102896] 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 [ 2384.108017] Lustre: Skipped 20 previous similar messages [ 2385.407084] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2385.410748] Lustre: Skipped 10 previous similar messages [ 2385.586326] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2385.591268] Lustre: Skipped 10 previous similar messages [ 2385.616437] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1283 to 0x0:1313 [ 2385.619849] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1251 to 0x0:1281 [ 2388.325594] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2398.856773] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2400.804286] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2408.781845] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 13:36:29 (1761240989) [ 2412.469683] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2422.241231] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2422.251708] LustreError: Skipped 10 previous similar messages [ 2439.689045] LustreError: 137-5: lustre-MDT0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2441.684823] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1283 to 0x0:1313 [ 2441.688917] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1315 to 0x0:1345 [ 2444.196117] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2452.871800] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2454.380314] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2462.558962] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 13:37:23 (1761241043) [ 2465.950159] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2497.409969] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1315 to 0x0:1345 [ 2497.429559] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1347 to 0x0:1377 [ 2500.104237] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2507.697913] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2508.994500] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2516.092328] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 13:38:17 (1761241097) [ 2519.329898] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2548.076660] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1379 to 0x0:1409 [ 2548.077061] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1347 to 0x0:1377 [ 2550.315767] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2558.436793] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2559.594168] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2566.721331] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 13:39:08 (1761241148) [ 2570.022425] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2597.664139] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1379 to 0x0:1409 [ 2597.667323] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1411 to 0x0:1441 [ 2600.390853] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2608.299528] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2609.732475] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2617.474491] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 13:39:58 (1761241198) [ 2618.378597] Lustre: 83175:0:(genops.c:1710:obd_export_evict_by_uuid()) lustre-MDT0000: evicting d54afc0b-13e8-42b0-82a0-1a9026c309d0 at adminstrative request [ 2626.647970] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 13:40:07 (1761241207) [ 2629.294799] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2638.300993] LustreError: 84039:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 2638.309325] LustreError: 84039:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2638.319544] Lustre: 84087:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2638.330813] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2638.404938] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1448 to 0x0:1473 [ 2638.408603] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1415 to 0x0:1441 [ 2641.986286] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2652.749865] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 13:40:34 (1761241234) [ 2655.768416] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2663.153165] LustreError: 137-5: lustre-MDT0000_UUID: 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. [ 2663.556677] Lustre: *** cfs_fail_loc=1311, val=0*** [ 2663.583310] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2663.588459] LustreError: 85390:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 2663.593178] Lustre: Skipped 13 previous similar messages [ 2663.601827] LustreError: 85390:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2663.614237] Lustre: 85440:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2663.621727] Lustre: 85440:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 2663.630137] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2663.700232] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1452 to 0x0:1473 [ 2663.709294] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1484 to 0x0:1505 [ 2667.159778] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2672.545045] Lustre: *** cfs_fail_loc=1311, val=0*** [ 2679.006349] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 13:41:00 (1761241260) [ 2682.003400] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2691.388158] LustreError: 86774:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 2691.397338] LustreError: 86774:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2691.406105] Lustre: 86822:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2691.412292] Lustre: 86822:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 2691.417860] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2691.592876] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1511 to 0x0:1537 [ 2691.596767] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1480 to 0x0:1505 [ 2695.152295] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2706.607974] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 13:41:27 (1761241287) [ 2707.576032] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 2707.582189] LustreError: 87252:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000083b1464 x1846792552989440/t201863462916(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:700/0 lens 504/456 e 0 to 0 dl 1761241295 ref 1 fl Interpret:/0/0 rc 0/0 job:'rm.0' [ 2718.545912] LustreError: 87989:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 2718.550677] LustreError: 87989:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2718.555344] Lustre: 88036:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2718.558015] Lustre: 88036:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 2718.567767] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2718.643357] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1539 to 0x0:1569 [ 2718.648687] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1480 to 0x0:1537 [ 2722.276986] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2733.850632] Lustre: DEBUG MARKER: == replay-single test 36: don't resend cancel ============ 13:41:54 (1761241314) [ 2736.612700] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2763.763551] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 2763.766408] Lustre: Skipped 38 previous similar messages [ 2766.886234] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2779.250905] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1480 to 0x0:1569 [ 2779.254226] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1571 to 0x0:1601 [ 2785.362583] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 13:42:46 (1761241366) [ 2788.308430] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2796.292117] LustreError: 137-5: lustre-MDT0000_UUID: 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. [ 2796.299212] LustreError: Skipped 1 previous similar message [ 2796.699880] LustreError: 90798:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 2796.703795] LustreError: 90798:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2796.708832] Lustre: 90847:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2796.713149] Lustre: 90847:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 2796.718108] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2796.784576] Lustre: lustre-OST0001: deleting orphan objects from 0x0:1480 to 0x0:1601 [ 2796.787699] Lustre: lustre-OST0000: deleting orphan objects from 0x0:1571 to 0x0:1633 [ 2800.143897] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2810.687159] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 13:43:12 (1761241392) [ 2832.211754] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2833.805883] LustreError: 3032:0:(client.c:1256:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@0000000091505e96 x1846792565499008/t0(0) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'osp-syn-0-0.0' [ 2844.512278] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761241419/real 1761241419] req@000000002f9fa7c4 x1846792565500544/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761241426 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 2844.532222] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 149 previous similar messages [ 2851.104827] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2851.107877] Lustre: Skipped 13 previous similar messages [ 2854.125587] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2859.070273] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2002 to 0x0:2017 [ 2859.071452] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2034 to 0x0:2049 [ 2862.457247] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2863.494677] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2878.043090] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 13:44:19 (1761241459) [ 2894.806482] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2935.220857] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 2937.568904] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2418 to 0x0:2433 [ 2937.570545] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2450 to 0x0:2465 [ 2943.628504] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2945.042072] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2962.543256] Lustre: DEBUG MARKER: == replay-single test 40: cause recovery in ptlrpc, ensure IO continues ========================================================== 13:45:43 (1761241543) [ 2963.976296] Lustre: DEBUG MARKER: SKIP: replay-single test_40 layout_lock needs MDS connection for IO [ 2965.390872] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 13:45:46 (1761241546) [ 2967.385414] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 2968.246426] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 2968.259578] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 2968.274248] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2418 to 0x0:2465 [ 2974.068310] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 13:45:55 (1761241555) [ 2993.017213] LustreError: 96498:0:(osd_handler.c:698:osd_ro()) lustre-OST0000: *** setting device osd-zfs read-only *** [ 2993.027782] LustreError: 96498:0:(osd_handler.c:698:osd_ro()) Skipped 11 previous similar messages [ 2994.120567] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 3003.484471] Lustre: Failing over lustre-OST0000 [ 3003.486760] Lustre: Skipped 12 previous similar messages [ 3004.385123] 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 [ 3004.411019] Lustre: Skipped 26 previous similar messages [ 3004.413176] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3004.414173] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3005.446442] Lustre: lustre-OST0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 3005.592360] Lustre: server umount lustre-OST0000 complete [ 3005.596882] Lustre: Skipped 12 previous similar messages [ 3009.509436] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 3014.629195] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 3014.644821] LustreError: Skipped 1 previous similar message [ 3024.569976] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3024.572765] Lustre: Skipped 7 previous similar messages [ 3025.331450] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3025.334857] Lustre: Skipped 7 previous similar messages [ 3025.353725] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2867 to 0x0:2913 [ 3027.421398] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3083.147407] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 13:47:44 (1761241664) [ 3086.827251] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3097.057363] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3097.066959] LustreError: Skipped 11 previous similar messages [ 3114.470307] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7757bae5 to 0x1e87481c77592698 [ 3114.478044] Lustre: Skipped 12 previous similar messages [ 3115.116384] Lustre: *** cfs_fail_loc=204, val=2147483648*** [ 3115.116416] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2866 to 0x0:2881 [ 3118.149575] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3122.144273] LustreError: 98956:0:(osp_precreate.c:967:osp_precreate_cleanup_orphans()) lustre-OST0000-osc-MDT0000: cannot cleanup orphans: rc = -11 [ 3122.148518] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3123.175595] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2867 to 0x0:2945 [ 3127.356235] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3128.789638] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3146.615170] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 13:48:47 (1761241727) [ 3151.106794] LustreError: 98934:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3156.448162] LustreError: 98934:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3156.461841] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3156.534479] LustreError: 36291:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3158.550447] LustreError: 98934:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3163.616998] LustreError: 98934:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3163.635278] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3163.644375] LustreError: 99564:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3163.666252] LustreError: 99564:0:(libcfs_fail.h:180:cfs_race()) Skipped 1 previous similar message [ 3165.397476] LustreError: 99564:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3170.784982] LustreError: 99564:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3170.790534] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3170.804673] Lustre: Skipped 1 previous similar message [ 3170.815894] LustreError: 99564:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3172.559883] LustreError: 99564:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3177.955474] LustreError: 99564:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3177.992260] LustreError: 99564:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3179.424048] LustreError: 98934:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3184.608331] LustreError: 98934:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3184.611884] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3184.631148] Lustre: Skipped 3 previous similar messages [ 3184.634207] LustreError: 99638:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3192.769222] LustreError: 99638:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3192.771159] LustreError: 99638:0:(libcfs_fail.h:169:cfs_race()) Skipped 1 previous similar message [ 3197.921576] LustreError: 99638:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3197.928986] LustreError: 99638:0:(libcfs_fail.h:178:cfs_race()) Skipped 1 previous similar message [ 3204.576195] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3204.585296] Lustre: Skipped 3 previous similar messages [ 3204.590667] LustreError: 99638:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 701 waking [ 3212.946605] LustreError: 99564:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 701 sleeping [ 3212.954282] LustreError: 99564:0:(libcfs_fail.h:169:cfs_race()) Skipped 2 previous similar messages [ 3218.400191] LustreError: 99564:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 701 awake: rc=0 [ 3218.412169] LustreError: 99564:0:(libcfs_fail.h:178:cfs_race()) Skipped 2 previous similar messages [ 3225.977182] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 13:50:07 (1761241807) [ 3227.640276] LustreError: 99638:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3233.778562] Lustre: lustre-MDT0000: Export 000000009b9e9828 already connecting from 192.168.201.8@tcp [ 3235.517212] Lustre: lustre-MDT0000: Export 000000009b9e9828 already connecting from 192.168.201.8@tcp [ 3237.209428] Lustre: lustre-MDT0000: Export 000000009b9e9828 already connecting from 192.168.201.8@tcp [ 3240.283276] Lustre: lustre-MDT0000: Export 000000009b9e9828 already connecting from 192.168.201.8@tcp [ 3240.286654] Lustre: Skipped 1 previous similar message [ 3244.966348] Lustre: lustre-MDT0000: Export 000000009b9e9828 already connecting from 192.168.201.8@tcp [ 3244.970937] Lustre: Skipped 3 previous similar messages [ 3249.145091] LustreError: 99638:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 3249.152744] Lustre: 99638:0:(service.c:2348:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/2s); client may timeout req@0000000043093b4f x1846792554006016/t0(0) o38->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:0/0 lens 520/416 e 0 to 0 dl 1761241829 ref 1 fl Complete:H/0/0 rc 0/0 job:'lctl.0' [ 3253.056543] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 13:50:34 (1761241834) [ 3254.257379] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3254.266927] Lustre: Skipped 4 previous similar messages [ 3256.722911] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3265.990346] Lustre: *** cfs_fail_loc=712, val=0*** [ 3265.995215] LustreError: 36291:0:(service.c:1226:ptlrpc_check_req()) @@@ Invalid replay without recovery req@000000003fef04e2 x1846792565729344/t0(0) o400->lustre-MDT0000-mdtlov_UUID@0@lo:0/0 lens 224/0 e 0 to 0 dl 0 ref 1 fl New:/c0/ffffffff rc 0/-1 job:'ptlrpcd_rcv.0' [ 3266.016873] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 3266.306328] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3266.309496] Lustre: Skipped 16 previous similar messages [ 3266.309520] LustreError: 103217:0:(mdt_handler.c:7428:mdt_iocontrol()) lustre-MDT0000: Aborting recovery for device [ 3266.317955] LustreError: 103217:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3266.324701] Lustre: 103270:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3266.342057] Lustre: 103270:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 3266.345773] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3266.435272] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2867 to 0x0:2977 [ 3266.436668] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2866 to 0x0:2913 [ 3270.152751] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3309.799377] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3319.871861] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2866 to 0x0:2945 [ 3319.875050] Lustre: lustre-OST0000: deleting orphan objects from 0x0:2867 to 0x0:3009 [ 3324.978079] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3326.377467] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3334.792291] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 13:51:55 (1761241915) [ 3334.905424] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3342.858274] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 13:52:03 (1761241923) [ 3343.780853] Lustre: *** cfs_fail_loc=122, val=2147483648*** [ 3343.783143] LustreError: 104239:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000812b2225 x1846792554028736/t0(0) o700->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:582/0 lens 264/248 e 0 to 0 dl 1761241932 ref 1 fl Interpret:/0/0 rc 0/0 job:'touch.0' [ 3381.227300] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 3381.230028] Lustre: Skipped 24 previous similar messages [ 3385.815645] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3395.187164] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3011 to 0x0:3041 [ 3395.187251] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2947 to 0x0:2977 [ 3401.990039] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3403.891850] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3414.467514] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 13:53:14 (1761241994) [ 3417.574286] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 3417.591655] LustreError: Skipped 3 previous similar messages [ 3437.204291] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3052 to 0x0:3073 [ 3439.568684] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3447.194826] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3448.491521] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3521.026982] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 13:55:01 (1761242101) [ 3525.931564] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3539.936242] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761242115/real 1761242115] req@00000000307403dd x1846792565765696/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761242122 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:4.0' [ 3539.955253] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 54 previous similar messages [ 3557.355890] LustreError: 137-5: lustre-MDT0000_UUID: 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. [ 3557.377307] LustreError: Skipped 7 previous similar messages [ 3557.755441] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3557.758418] Lustre: Skipped 7 previous similar messages [ 3561.052898] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3573.756828] Lustre: *** cfs_fail_loc=216, val=0*** [ 3573.757563] Lustre: lustre-OST0001: deleting orphan objects from 0x0:2998 to 0x0:3041 [ 3573.758825] LustreError: 109114:0:(osp_precreate.c:967:osp_precreate_cleanup_orphans()) lustre-OST0000-osc-MDT0000: cannot cleanup orphans: rc = -30 [ 3574.816859] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3084 to 0x0:3105 [ 3640.175507] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 13:57:01 (1761242221) [ 3641.686333] 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 [ 3641.692187] Lustre: Skipped 12 previous similar messages [ 3641.695594] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3641.702920] Lustre: Skipped 2 previous similar messages [ 3641.709051] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3116 to 0x0:3137 [ 3642.586684] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3116 to 0x0:3169 [ 3651.374744] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 13:57:12 (1761242232) [ 3653.155588] Lustre: Failing over lustre-MDT0000 [ 3653.157486] Lustre: Skipped 6 previous similar messages [ 3653.442892] Lustre: server umount lustre-MDT0000 complete [ 3653.446139] Lustre: Skipped 6 previous similar messages [ 3685.447947] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3695.089892] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3695.095092] Lustre: Skipped 5 previous similar messages [ 3695.128739] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 3695.134935] LustreError: 110817:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000ec9b33ff x1846792554080960/t0(0) o101->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:178/0 lens 328/344 e 0 to 0 dl 1761242283 ref 1 fl Complete:/40/0 rc 0/0 job:'ldlm_lock_repla.0' [ 3702.270138] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:58 [ 3702.451205] Lustre: lustre-MDT0000: Recovery over after 0:07, of 1 clients 1 recovered and 0 were evicted. [ 3702.466241] Lustre: Skipped 5 previous similar messages [ 3702.536206] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3116 to 0x0:3201 [ 3702.536206] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3053 to 0x0:3073 [ 3709.959376] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3711.742673] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3720.543213] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 13:58:21 (1761242301) [ 3722.559433] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 3726.345528] LustreError: 111994:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3726.363024] LustreError: 111994:0:(osd_handler.c:698:osd_ro()) Skipped 3 previous similar messages [ 3727.242073] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3738.464199] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3738.484142] LustreError: Skipped 5 previous similar messages [ 3756.008268] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c775958b0 to 0x1e87481c77595d5d [ 3756.019761] Lustre: Skipped 5 previous similar messages [ 3758.734816] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3053 to 0x0:3105 [ 3758.739981] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3203 to 0x0:3233 [ 3760.082325] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3766.979623] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3768.188841] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3775.467822] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 13:59:16 (1761242356) [ 3776.593452] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 3781.158329] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3801.078049] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3203 to 0x0:3265 [ 3801.078076] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3107 to 0x0:3137 [ 3803.555647] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3810.026637] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3811.155903] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3816.790830] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 13:59:58 (1761242398) [ 3818.526263] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 3822.594521] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3824.125919] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 3854.808488] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3855.854943] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3203 to 0x0:3297 [ 3855.856711] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3139 to 0x0:3169 [ 3864.570218] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 14:00:45 (1761242445) [ 3866.661376] Lustre: *** cfs_fail_loc=13b, val=315*** [ 3866.665864] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 3866.667927] LustreError: 116084:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@0000000083097e7c x1846792554106304/t261993005073(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:349/0 lens 392/456 e 0 to 0 dl 1761242454 ref 1 fl Interpret:/0/0 rc 0/0 job:'multiop.0' [ 3895.177705] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3895.201880] Lustre: Skipped 10 previous similar messages [ 3898.844791] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3907.117925] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3299 to 0x0:3329 [ 3907.127405] Lustre: 117439:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@000000007fa3de78 x1846792554106304/t261993005073(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:390/0 lens 392/456 e 0 to 0 dl 1761242495 ref 1 fl Interpret:/2/0 rc 0/0 job:'multiop.0' [ 3912.988477] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3914.747763] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3923.254591] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 14:01:44 (1761242504) [ 3924.204301] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3924.208506] LustreError: 118142:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@0000000016c39029 x1846792554113792/t266287972368(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:407/0 lens 504/448 e 0 to 0 dl 1761242512 ref 1 fl Interpret:/0/0 rc 0/0 job:'mcreate.0' [ 3929.007677] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3930.605861] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 3930.616365] Lustre: Skipped 2 previous similar messages [ 3930.634251] Lustre: 117435:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@000000003680b3e8 x1846792554113792/t266287972368(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:413/0 lens 504/448 e 0 to 0 dl 1761242518 ref 1 fl Interpret:/2/0 rc 0/0 job:'mcreate.0' [ 3960.312729] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 3960.376140] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3331 to 0x0:3361 [ 3960.377578] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3139 to 0x0:3201 [ 3967.101243] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3968.262802] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3975.166350] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 14:02:36 (1761242556) [ 3976.066547] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3976.069328] LustreError: 119179:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000e8373395 x1846792554121344/t270582939664(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:459/0 lens 504/448 e 0 to 0 dl 1761242564 ref 1 fl Interpret:/0/0 rc 0/0 job:'mcreate.0' [ 3977.789067] Lustre: *** cfs_fail_loc=13b, val=315*** [ 3980.690798] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4001.121523] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 4001.124375] Lustre: Skipped 26 previous similar messages [ 4004.789871] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4016.115556] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3331 to 0x0:3393 [ 4016.115858] Lustre: 120904:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000bfee2b72 x1846792554121472/t270582939665(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:499/0 lens 392/456 e 0 to 0 dl 1761242604 ref 1 fl Interpret:/2/0 rc 0/0 job:'multiop.0' [ 4016.115987] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3203 to 0x0:3233 [ 4016.135486] Lustre: 120904:0:(mdt_recovery.c:200:mdt_req_from_lrd()) Skipped 1 previous similar message [ 4023.708154] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 14:03:24 (1761242604) [ 4024.567339] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4024.569224] Lustre: Skipped 1 previous similar message [ 4024.570964] LustreError: 120900:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000350d8570 x1846792554128256/t274877906960(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:507/0 lens 504/448 e 0 to 0 dl 1761242612 ref 1 fl Interpret:/0/0 rc 0/0 job:'mcreate.0' [ 4024.580848] LustreError: 120900:0:(ldlm_lib.c:3224:target_send_reply_msg()) Skipped 1 previous similar message [ 4026.284895] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4026.286414] Lustre: Skipped 1 previous similar message [ 4030.356176] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4030.967463] Lustre: 120901:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000d7462c16 x1846792554128256/t274877906960(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:514/0 lens 504/448 e 0 to 0 dl 1761242619 ref 1 fl Interpret:/2/0 rc 0/0 job:'mcreate.0' [ 4059.742587] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3395 to 0x0:3425 [ 4059.742804] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3203 to 0x0:3265 [ 4061.183245] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4069.609665] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 14:04:10 (1761242650) [ 4070.434825] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4072.110355] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4072.112566] LustreError: 122517:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@0000000074930520 x1846792554135168/t279172874256(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:555/0 lens 392/456 e 0 to 0 dl 1761242660 ref 1 fl Interpret:/0/0 rc 0/0 job:'multiop.0' [ 4075.874379] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4106.005238] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4110.319677] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3395 to 0x0:3457 [ 4110.319716] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3267 to 0x0:3297 [ 4110.321755] Lustre: 124018:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@000000003cc3921a x1846792554135168/t279172874256(0) o35->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:593/0 lens 392/456 e 0 to 0 dl 1761242698 ref 1 fl Interpret:/2/0 rc 0/0 job:'multiop.0' [ 4117.622194] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 14:04:58 (1761242698) [ 4118.379931] Lustre: *** cfs_fail_loc=12b, val=2147483991*** [ 4118.386251] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 4118.390978] Lustre: Skipped 1 previous similar message [ 4118.393226] LustreError: 124015:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000daf36a8a x1846792554141120/t283467841550(0) o101->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:601/0 lens 664/600 e 0 to 0 dl 1761242706 ref 1 fl Interpret:/0/0 rc 301/0 job:'touch.0' [ 4124.675664] Lustre: 124014:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000690e0d3e x1846792554141120/t283467841550(0) o101->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:607/0 lens 664/3424 e 0 to 0 dl 1761242712 ref 1 fl Interpret:/2/0 rc 0/0 job:'touch.0' [ 4129.772498] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 14:05:10 (1761242710) [ 4133.249603] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4134.911425] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 4146.016227] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761242721/real 1761242721] req@0000000083750135 x1846792565849344/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1761242728 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 4146.034906] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 54 previous similar messages [ 4156.946337] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4167.609288] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3299 to 0x0:3329 [ 4167.611325] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3395 to 0x0:3489 [ 4172.469500] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4173.909212] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4191.027969] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 14:06:12 (1761242772) [ 4194.946833] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4224.832674] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4224.835872] Lustre: Skipped 10 previous similar messages [ 4227.880279] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4238.404875] Lustre: lustre-OST0001: deleting orphan objects from 0x0:3299 to 0x0:3361 [ 4238.404955] Lustre: lustre-OST0000: deleting orphan objects from 0x0:3491 to 0x0:3521 [ 4243.122494] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4244.242206] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4247.987709] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4257.389786] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 14:07:18 (1761242838) [ 4297.660806] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4299.382056] Lustre: Failing over lustre-MDT0000 [ 4299.383865] Lustre: Skipped 10 previous similar messages [ 4299.794220] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 4300.274103] Lustre: server umount lustre-MDT0000 complete [ 4300.276967] Lustre: Skipped 10 previous similar messages [ 4308.937818] 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 [ 4308.949528] Lustre: Skipped 23 previous similar messages [ 4331.194484] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4332.398609] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4332.404120] Lustre: Skipped 10 previous similar messages [ 4332.591161] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4332.595527] Lustre: Skipped 10 previous similar messages [ 4332.615130] Lustre: lustre-OST0000: deleting orphan objects from 0x0:4772 to 0x0:4801 [ 4332.618330] Lustre: lustre-OST0001: deleting orphan objects from 0x0:4612 to 0x0:4641 [ 4338.735353] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4339.916369] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4406.245822] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 14:09:47 (1761242987) [ 4409.217797] LustreError: 131143:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4409.229149] LustreError: 131143:0:(osd_handler.c:698:osd_ro()) Skipped 9 previous similar messages [ 4409.865332] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4421.088319] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4421.096035] LustreError: Skipped 10 previous similar messages [ 4438.503747] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c775aeac0 to 0x1e87481c775d9bd7 [ 4438.517616] Lustre: Skipped 10 previous similar messages [ 4440.124974] Lustre: lustre-OST0000: deleting orphan objects from 0x0:4772 to 0x0:4833 [ 4440.127829] Lustre: lustre-OST0001: deleting orphan objects from 0x0:4643 to 0x0:4673 [ 4441.837845] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4448.550251] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4449.662405] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4457.315275] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid [ 4458.696293] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 4463.788704] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 14:10:45 (1761243045) [ 4470.095368] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 4515.312741] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnecting [ 4515.324925] Lustre: Skipped 2 previous similar messages [ 4517.292509] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4517.299833] LustreError: 131761:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000820fefaa x1846792555619648/t300647710728(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:281/0 lens 66040/440 e 0 to 0 dl 1761243141 ref 1 fl Interpret:/0/0 rc 0/0 job:'setfattr.0' [ 4560.376488] Lustre: 131761:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000f0fbc857 x1846792555619648/t300647710728(0) o36->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:324/0 lens 66040/440 e 0 to 0 dl 1761243184 ref 1 fl Interpret:/2/0 rc 0/0 job:'setfattr.0' [ 4568.528710] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 4569.882741] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 14:12:31 (1761243151) [ 4578.020969] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4597.224673] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4597.227768] Lustre: Skipped 8 previous similar messages [ 4600.269340] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4602.236694] Lustre: lustre-OST0000: deleting orphan objects from 0x0:4935 to 0x0:4961 [ 4602.237945] Lustre: lustre-OST0001: deleting orphan objects from 0x0:4774 to 0x0:4801 [ 4602.338620] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 4602.347079] Lustre: Skipped 21 previous similar messages [ 4608.366423] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4609.736620] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4621.008144] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 14:13:22 (1761243202) [ 4641.007197] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 4653.545893] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 4658.656969] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 4668.898035] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 4668.934522] LustreError: Skipped 1 previous similar message [ 4672.729484] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4686.050482] LustreError: 136850:0:(ldlm_lib.c:2882:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 4686.054621] Lustre: 136329:0:(ldlm_lib.c:2288:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4686.058608] Lustre: 136329:0:(ldlm_lib.c:2288:target_recovery_overseer()) Skipped 2 previous similar messages [ 4686.062395] Lustre: 136329:0:(ldlm_lib.c:1803:abort_req_replay_queue()) @@@ aborted: req@00000000758278ff x1846792566251008/t0(17179870573) o6->lustre-MDT0000-mdtlov_UUID@0@lo:422/0 lens 544/0 e 2 to 0 dl 1761243282 ref 1 fl Complete:/4/ffffffff rc 0/-1 job:'osp-syn-0-0.0' [ 4686.072101] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -19 [ 4686.076818] Lustre: 136329:0:(ofd_obd.c:554:ofd_postrecov()) lustre-OST0000: auto trigger paused LFSCK failed: rc = -6 [ 4686.078064] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 4691.426767] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 4704.867797] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4708.212979] LustreError: 3031:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 0, old was -19 req@00000000d7462c16 x1846792566251008/t17179870573(17179870573) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 3 to 0 dl 1761243304 ref 2 fl Interpret:RQU/4/0 rc 0/0 job:'osp-syn-0-0.0' [ 4709.020598] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5362 to 0x0:5377 [ 4714.900097] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 4716.418936] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4754.731606] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 14:15:36 (1761243336) [ 4766.560180] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761243341/real 1761243341] req@0000000030c4fc73 x1846792566316672/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761243348 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:4.0' [ 4766.588591] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 45 previous similar messages [ 4784.494820] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5202 to 0x0:5217 [ 4784.495430] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5362 to 0x0:5409 [ 4785.991461] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4821.392099] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4821.655216] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5202 to 0x0:5249 [ 4821.655778] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5362 to 0x0:5441 [ 4829.819518] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4831.048859] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4837.603875] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 14:16:58 (1761243418) [ 4853.236968] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4853.246690] LustreError: Skipped 2 previous similar messages [ 4853.729627] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4866.975632] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4866.982047] Lustre: Skipped 7 previous similar messages [ 4868.585480] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5443 to 0x0:5473 [ 4870.233764] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4878.232677] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 4879.496613] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4887.780350] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 14:17:48 (1761243468) [ 4896.590429] Lustre: *** cfs_fail_loc=605, val=0*** [ 4896.594087] LustreError: 142806:0:(llog_obd.c:207:llog_setup()) MGS: ctxt 0 lop_setup=000000000091fa55 failed: rc = -95 [ 4896.597913] LustreError: 142806:0:(obd_config.c:774:class_setup()) setup MGS failed (-95) [ 4896.624608] LustreError: 142806:0:(obd_mount.c:200:lustre_start_simple()) MGS setup error -95 [ 4896.636776] LustreError: 142806:0:(obd_mount_server.c:131:server_deregister_mount()) MGS not registered [ 4896.651172] LustreError: 15e-a: Failed to start MGS 'MGS' (-95). Is the 'mgs' module loaded? [ 4896.661183] LustreError: 142806:0:(obd_mount_server.c:1644:server_put_super()) no obd lustre-MDT0000 [ 4896.739733] LustreError: 142806:0:(super25.c:183:lustre_fill_super()) llite: Unable to mount : rc = -95 [ 4906.606765] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5251 to 0x0:5281 [ 4906.609904] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5443 to 0x0:5505 [ 4908.532233] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4914.913968] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 14:18:15 (1761243495) [ 4917.642474] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4920.218072] Lustre: Failing over lustre-MDT0000 [ 4920.220575] Lustre: Skipped 8 previous similar messages [ 4920.582362] Lustre: server umount lustre-MDT0000 complete [ 4920.584103] Lustre: Skipped 9 previous similar messages [ 4941.297958] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4941.301549] Lustre: Skipped 8 previous similar messages [ 4941.319242] Lustre: *** cfs_fail_loc=707, val=0*** [ 4943.103738] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 4944.867580] 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 [ 4944.885993] Lustre: Skipped 14 previous similar messages [ 4981.765141] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:59 [ 4982.289799] Lustre: lustre-MDT0000: Recovery over after 0:41, of 1 clients 1 recovered and 0 were evicted. [ 4982.293848] Lustre: Skipped 8 previous similar messages [ 4982.319688] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5518 to 0x0:5537 [ 4982.323430] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5295 to 0x0:5313 [ 4987.566248] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4989.002396] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4996.967954] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 14:19:38 (1761243578) [ 5025.790285] LustreError: 144499:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 6000ms [ 5031.857118] LustreError: 144499:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5047.359044] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 14:20:28 (1761243628) [ 5075.410753] LustreError: 6360:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 224 sleeping for 6000ms [ 5081.448188] LustreError: 6360:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 224 awake [ 5087.356312] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 14:21:08 (1761243668) [ 5113.897897] LustreError: 145098:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 5000ms [ 5118.904125] LustreError: 145098:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5121.011465] LustreError: 144499:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 10000ms [ 5131.117758] LustreError: 144499:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5148.127139] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 14:22:09 (1761243729) [ 5203.797833] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 14:23:05 (1761243785) [ 5231.256203] LustreError: 145098:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 400ms [ 5231.672155] LustreError: 145098:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5239.380404] LustreError: 144501:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 400ms [ 5239.385646] LustreError: 144501:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 22 previous similar messages [ 5239.808186] LustreError: 144501:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5239.816860] LustreError: 144501:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 22 previous similar messages [ 5255.649290] LustreError: 6359:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a sleeping for 400ms [ 5255.660736] LustreError: 6359:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 53 previous similar messages [ 5256.074815] LustreError: 17668:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50a awake [ 5256.078651] LustreError: 17668:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 52 previous similar messages [ 5264.079352] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 14:24:05 (1761243845) [ 5296.218706] Lustre: DEBUG MARKER: phase 2 [ 5303.927941] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 14:24:45 (1761243885) [ 5383.345356] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 14:26:04 (1761243964) [ 5384.663499] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 5386.311410] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 1mdts recovery; 1 clients ========================================================== 14:26:07 (1761243967) [ 5391.090297] Lustre: DEBUG MARKER: Started rundbench load pid=131288 ... [ 5395.762717] LustreError: 151288:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5395.773350] LustreError: 151288:0:(osd_handler.c:698:osd_ro()) Skipped 3 previous similar messages [ 5396.812361] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5399.663973] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 5411.744147] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761243987/real 1761243987] req@0000000035e2c396 x1846792566414848/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761243994 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 5411.760995] Lustre: 3034:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 45 previous similar messages [ 5411.774817] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5411.788721] LustreError: Skipped 5 previous similar messages [ 5429.221031] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c775ee83b to 0x1e87481c775f3ee9 [ 5429.231425] Lustre: Skipped 5 previous similar messages [ 5429.238287] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 5429.251349] Lustre: Skipped 15 previous similar messages [ 5429.812012] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5429.815465] Lustre: Skipped 7 previous similar messages [ 5433.414334] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5440.927975] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5394 to 0x0:5409 [ 5440.928742] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5639 to 0x0:5665 [ 5445.461171] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5447.255453] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5453.743573] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5456.318071] Lustre: DEBUG MARKER: test_70b fail mds1 2 times [ 5484.281463] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5484.288804] Lustre: Skipped 3 previous similar messages [ 5488.145945] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5435 to 0x0:5473 [ 5488.146566] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5690 to 0x0:5729 [ 5488.303333] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5496.111898] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5497.493042] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5503.121060] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5505.294648] Lustre: DEBUG MARKER: test_70b fail mds1 3 times [ 5506.864852] LustreError: 153800:0:(ldlm_lockd.c:1427:ldlm_handle_enqueue0()) ### lock on destroyed export 00000000558a7bfd ns: mdt-lustre-MDT0000_UUID lock: 00000000ee0dc535/0x1e87481c775ffeeb lrc: 3/0,0 mode: CW/CW res: [0x20001b1b3:0xee2:0x0].0x0 bits 0x5/0x0 rrc: 2 type: IBT gid 0 flags: 0x50200000000000 nid: 192.168.201.8@tcp remote: 0x539dccd3eb0571ed expref: 4 pid: 153800 timeout: 0 lvb_type: 0 [ 5507.566691] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 5511.141536] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5511.152555] Lustre: Skipped 1 previous similar message [ 5512.687986] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 5533.773125] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5539.912209] Lustre: lustre-OST0001: deleting orphan objects from 0x0:5519 to 0x0:5537 [ 5539.915400] Lustre: lustre-OST0000: deleting orphan objects from 0x0:5775 to 0x0:5793 [ 5544.988483] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5546.327596] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5554.106718] Lustre: DEBUG MARKER: == replay-single test 70c: tar 1mdts recovery ============ 14:28:54 (1761244134) [ 5678.561833] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5690.384564] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 5691.957713] Lustre: Failing over lustre-MDT0000 [ 5691.960191] Lustre: Skipped 3 previous similar messages [ 5692.019239] LustreError: 3033:0:(client.c:1256:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@00000000ed12ad20 x1846792566686912/t0(0) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'osp-syn-0-0.0' [ 5692.043839] LustreError: 3033:0:(client.c:1256:ptlrpc_import_delay_req()) Skipped 7 previous similar messages [ 5692.411861] Lustre: server umount lustre-MDT0000 complete [ 5692.418843] Lustre: Skipped 3 previous similar messages [ 5704.096722] 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 [ 5704.108356] Lustre: Skipped 6 previous similar messages [ 5713.399642] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5719.603867] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5719.607268] Lustre: Skipped 3 previous similar messages [ 5726.426970] Lustre: lustre-MDT0000: Recovery over after 0:07, of 1 clients 1 recovered and 0 were evicted. [ 5726.432135] Lustre: Skipped 3 previous similar messages [ 5726.455020] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6437 to 0x0:6465 [ 5726.455452] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6181 to 0x0:6209 [ 5731.870177] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5733.430763] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5827.017297] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 1mdts recovery ========================================================== 14:33:28 (1761244408) [ 5828.349625] Lustre: DEBUG MARKER: SKIP: replay-single test_70d needs >= 2 MDTs [ 5829.874097] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 14:33:31 (1761244411) [ 5831.933469] Lustre: DEBUG MARKER: SKIP: replay-single test_70e needs >= 2 MDTs [ 5833.990931] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 14:33:34 (1761244414) [ 5842.858484] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5845.317840] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 5847.552289] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5847.563408] LustreError: Skipped 5 previous similar messages [ 5849.569083] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 5857.778383] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5857.790381] LustreError: Skipped 4 previous similar messages [ 5868.213110] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6747 to 0x0:6785 [ 5871.718351] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5881.846553] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5883.607164] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5895.012340] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5897.544255] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 5899.699250] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5899.715678] LustreError: Skipped 3 previous similar messages [ 5918.879785] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6747 to 0x0:6817 [ 5921.562335] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 5935.992859] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5938.521667] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5950.461869] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 14:35:31 (1761244531) [ 5951.539526] Lustre: DEBUG MARKER: SKIP: replay-single test_71a needs >= 2 MDTs [ 5952.915843] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 14:35:34 (1761244534) [ 5956.597022] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5992.016892] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6001.142028] Lustre: *** cfs_fail_loc=302, val=2147483648*** [ 6008.331332] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:58 [ 6008.407767] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6491 to 0x0:6529 [ 6008.407767] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6819 to 0x0:6849 [ 6014.810614] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6017.079541] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6026.732444] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 14:36:47 (1761244607) [ 6030.065060] LustreError: 163120:0:(osd_handler.c:698:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6030.072253] LustreError: 163120:0:(osd_handler.c:698:osd_ro()) Skipped 6 previous similar messages [ 6031.097171] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6046.112195] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761244621/real 1761244621] req@00000000f6fe31ce x1846792566921792/t0(0) o400->MGC192.168.201.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1761244628 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 6046.126016] Lustre: 3032:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 6046.142105] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6046.152792] LustreError: Skipped 4 previous similar messages [ 6052.322970] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c77676441 to 0x1e87481c776768d9 [ 6052.326583] Lustre: Skipped 4 previous similar messages [ 6052.333947] Lustre: MGC192.168.201.108@tcp: Connection restored to (at 0@lo) [ 6052.343339] Lustre: Skipped 16 previous similar messages [ 6052.795719] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6052.814667] Lustre: Skipped 6 previous similar messages [ 6056.068428] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6061.611799] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 6061.615769] LustreError: 163770:0:(ldlm_lib.c:3224:target_send_reply_msg()) @@@ dropping reply req@00000000392d6c2d x1846792560262784/t343597383683(343597383683) o101->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:279/0 lens 592/600 e 0 to 0 dl 1761244649 ref 1 fl Interpret:/4/0 rc 301/0 job:'multiop.0' [ 6067.735358] Lustre: lustre-MDT0000: Client d54afc0b-13e8-42b0-82a0-1a9026c309d0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:59 [ 6067.769462] Lustre: 164229:0:(mdt_recovery.c:200:mdt_req_from_lrd()) @@@ restoring transno req@00000000d4c041d0 x1846792560262784/t343597383683(343597383683) o101->d54afc0b-13e8-42b0-82a0-1a9026c309d0@192.168.201.8@tcp:286/0 lens 592/3424 e 0 to 0 dl 1761244656 ref 1 fl Interpret:/6/0 rc 0/0 job:'multiop.0' [ 6067.965415] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6531 to 0x0:6561 [ 6067.965687] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6819 to 0x0:6881 [ 6074.148671] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6075.661864] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6083.614748] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 14:37:44 (1761244664) [ 6088.679838] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6088.690854] LustreError: 137-5: lustre-OST0000_UUID: 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. [ 6088.702154] LustreError: Skipped 7 previous similar messages [ 6118.809812] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6118.813248] Lustre: Skipped 6 previous similar messages [ 6118.980179] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6531 to 0x0:6593 [ 6123.325492] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6130.678417] Lustre: lustre-OST0000: Denying connection for new client 711b4f5d-cdaa-45f6-975e-aaef38dfb38f (at 192.168.201.8@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 6130.701994] Lustre: Skipped 11 previous similar messages [ 6130.935505] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6819 to 0x0:6913 [ 6133.959589] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6144.024632] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 14:38:44 (1761244724) [ 6145.274054] Lustre: DEBUG MARKER: SKIP: replay-single test_80a needs >= 2 MDTs [ 6147.021387] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 14:38:47 (1761244727) [ 6148.292784] Lustre: DEBUG MARKER: SKIP: replay-single test_80b needs >= 2 MDTs [ 6149.632755] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 14:38:50 (1761244730) [ 6150.667815] Lustre: DEBUG MARKER: SKIP: replay-single test_80c needs >= 2 MDTs [ 6152.031383] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 14:38:53 (1761244733) [ 6153.241477] Lustre: DEBUG MARKER: SKIP: replay-single test_80d needs >= 2 MDTs [ 6154.464976] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 14:38:55 (1761244735) [ 6155.727799] Lustre: DEBUG MARKER: SKIP: replay-single test_80e needs >= 2 MDTs [ 6157.005434] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 14:38:58 (1761244738) [ 6158.026478] Lustre: DEBUG MARKER: SKIP: replay-single test_80f needs >= 2 MDTs [ 6159.546125] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 14:39:00 (1761244740) [ 6160.908866] Lustre: DEBUG MARKER: SKIP: replay-single test_80g needs >= 2 MDTs [ 6162.630076] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 14:39:03 (1761244743) [ 6164.283250] Lustre: DEBUG MARKER: SKIP: replay-single test_80h needs >= 2 MDTs [ 6165.988147] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 14:39:07 (1761244747) [ 6167.438659] Lustre: DEBUG MARKER: SKIP: replay-single test_81a needs >= 2 MDTs [ 6169.042324] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 14:39:10 (1761244750) [ 6170.702977] Lustre: DEBUG MARKER: SKIP: replay-single test_81b needs >= 2 MDTs [ 6172.670947] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 14:39:13 (1761244753) [ 6174.022048] Lustre: DEBUG MARKER: SKIP: replay-single test_81c needs >= 2 MDTs [ 6175.636671] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 14:39:16 (1761244756) [ 6177.024802] Lustre: DEBUG MARKER: SKIP: replay-single test_81d needs >= 2 MDTs [ 6178.448365] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 14:39:19 (1761244759) [ 6179.827875] Lustre: DEBUG MARKER: SKIP: replay-single test_81e needs >= 2 MDTs [ 6181.371231] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 14:39:22 (1761244762) [ 6182.603561] Lustre: DEBUG MARKER: SKIP: replay-single test_81f needs >= 2 MDTs [ 6184.107500] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 14:39:25 (1761244765) [ 6185.454595] Lustre: DEBUG MARKER: SKIP: replay-single test_81g needs >= 2 MDTs [ 6186.896155] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 14:39:28 (1761244768) [ 6188.081822] Lustre: DEBUG MARKER: SKIP: replay-single test_81h needs >= 2 MDTs [ 6189.756728] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 14:39:30 (1761244770) [ 6191.510343] Lustre: 168390:0:(genops.c:1710:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 711b4f5d-cdaa-45f6-975e-aaef38dfb38f at adminstrative request [ 6198.920275] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 14:39:39 (1761244779) [ 6241.430369] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6249.487048] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6645 to 0x0:6689 [ 6249.494431] Lustre: lustre-OST0000: deleting orphan objects from 0x0:6965 to 0x0:7009 [ 6254.951953] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6256.881533] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6268.692388] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 14:40:48 (1761244848) [ 6284.294633] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6284.306650] LustreError: Skipped 4 previous similar messages [ 6285.287789] LustreError: 11-0: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6304.819862] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7110 to 0x0:7137 [ 6307.244304] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6316.290676] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6317.434796] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6327.631718] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 14:41:48 (1761244908) [ 6333.175710] Lustre: Failing over lustre-MDT0000 [ 6333.180233] Lustre: Skipped 8 previous similar messages [ 6333.410047] 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 [ 6333.418502] Lustre: Skipped 12 previous similar messages [ 6333.437099] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6333.437099] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6333.666416] Lustre: server umount lustre-MDT0000 complete [ 6333.674204] Lustre: Skipped 8 previous similar messages [ 6340.673949] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6645 to 0x0:6721 [ 6340.677321] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7110 to 0x0:7169 [ 6344.421130] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6351.803609] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 14:42:12 (1761244932) [ 6355.895066] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6376.078269] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 6376.096017] Lustre: Skipped 7 previous similar messages [ 6376.421480] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 6376.428301] Lustre: Skipped 7 previous similar messages [ 6376.437765] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7110 to 0x0:7201 [ 6378.781203] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6386.955877] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6388.376598] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6395.719957] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 14:42:56 (1761244976) [ 6399.955765] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6412.790118] LustreError: 137-5: lustre-OST0000_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6412.807089] LustreError: Skipped 16 previous similar messages [ 6421.256772] LustreError: 168-f: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.201.8@tcp inode [0x200029441:0x5:0x0] object 0x0:7202 extent [0-1048575]: client csum 8a401f1e, server csum 135ef2be [ 6421.600812] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7203 to 0x0:7233 [ 6422.683204] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6430.348132] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6431.874776] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6439.223851] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 14:43:40 (1761245020) [ 6442.107117] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 6444.667192] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6448.627290] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 6451.541152] LustreError: 36296:0:(ldlm_lockd.c:2526:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1761245033 with bad export cookie 2199806230093350724 [ 6488.666549] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6502.944775] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6763 to 0x0:6785 [ 6509.602262] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7203 to 0x0:7265 [ 6510.949985] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6522.697437] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 14:45:04 (1761245104) [ 6537.716880] Lustre: lustre-OST0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 6571.987456] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6582.945534] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6763 to 0x0:6817 [ 6589.981777] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6592.122851] Lustre: lustre-OST0000: Denying connection for new client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:05 [ 6612.975358] Lustre: lustre-OST0000: Denying connection for new client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:45 [ 6612.993618] Lustre: Skipped 3 previous similar messages [ 6648.822927] Lustre: lustre-OST0000: Denying connection for new client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:09 [ 6648.854163] Lustre: Skipped 6 previous similar messages [ 6658.000187] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 6658.006060] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 6658.057972] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.201.108@tcp (at 0@lo) [ 6658.070750] Lustre: Skipped 19 previous similar messages [ 6658.073160] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7276 to 0x0:7297 [ 6661.864173] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 60 sec [ 6676.289652] Lustre: DEBUG MARKER: free_before: 7518208 free_after: 7518208 [ 6684.494951] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 14:47:45 (1761245265) [ 6689.823438] LustreError: 137-5: lustre-OST0001_UUID: not available for connect from 192.168.201.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6689.838067] LustreError: Skipped 40 previous similar messages [ 6690.786362] LustreError: 11-0: lustre-OST0001-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6706.927545] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 6706.940031] Lustre: Skipped 9 previous similar messages [ 6708.857086] Lustre: lustre-OST0001: deleting orphan objects from 0x0:6820 to 0x0:6849 [ 6710.522244] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6718.609317] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 14:48:19 (1761245299) [ 6722.044979] Lustre: lustre-OST0000: Not available for connect from 192.168.201.8@tcp (stopping) [ 6722.050612] Lustre: Skipped 1 previous similar message [ 6740.094555] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6740.096655] Lustre: Skipped 11 previous similar messages [ 6741.379230] LustreError: 183337:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 715 sleeping for 40000ms [ 6741.384350] LustreError: 183337:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 6742.054541] Lustre: *** cfs_fail_loc=715, val=0*** [ 6743.178714] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6747.629707] Lustre: lustre-OST0000: Client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp) reconnected, waiting for 2 clients in recovery for 0:58 [ 6748.640139] Lustre: 3031:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761245323/real 1761245323] req@00000000ce7ed50b x1846792567025920/t0(0) o400->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 224/224 e 0 to 1 dl 1761245330 ref 1 fl Rpc:XQr/c0/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' [ 6748.642391] Lustre: *** cfs_fail_loc=715, val=0*** [ 6748.663202] Lustre: 3031:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 6748.663457] Lustre: Skipped 1 previous similar message [ 6748.677361] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 0:57 [ 6749.731142] Lustre: *** cfs_fail_loc=715, val=0*** [ 6754.787951] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 0:51 [ 6755.809331] Lustre: *** cfs_fail_loc=715, val=0*** [ 6761.952622] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 0:44 [ 6761.958486] Lustre: Skipped 1 previous similar message [ 6762.977506] Lustre: *** cfs_fail_loc=715, val=0*** [ 6762.979256] Lustre: Skipped 1 previous similar message [ 6769.122667] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 0:36 [ 6769.126976] Lustre: Skipped 1 previous similar message [ 6777.312971] Lustre: *** cfs_fail_loc=715, val=0*** [ 6777.314802] Lustre: Skipped 3 previous similar messages [ 6781.384104] LustreError: 183337:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 715 awake [ 6781.389612] LustreError: 183337:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 6781.513504] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7301 to 0x0:7329 [ 6788.020307] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6789.875564] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6797.502201] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 14:49:38 (1761245378) [ 6809.465746] LustreError: 166-1: MGC192.168.201.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6809.470704] LustreError: Skipped 5 previous similar messages [ 6825.954726] Lustre: Evicted from MGS (at 192.168.201.108@tcp) after server handle changed from 0x1e87481c7767e9cd to 0x1e87481c7767f764 [ 6825.964401] Lustre: Skipped 5 previous similar messages [ 6829.627778] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 6830.085208] LustreError: 184910:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 715 sleeping for 80000ms [ 6831.136461] Lustre: *** cfs_fail_loc=715, val=0*** [ 6831.139639] Lustre: Skipped 1 previous similar message [ 6837.232038] Lustre: lustre-MDT0000: Client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:58 [ 6837.245463] Lustre: Skipped 3 previous similar messages [ 6858.735598] Lustre: lustre-MDT0000: Client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:37 [ 6858.777757] Lustre: Skipped 2 previous similar messages [ 6866.912278] Lustre: *** cfs_fail_loc=715, val=0*** [ 6866.915309] Lustre: Skipped 4 previous similar messages [ 6894.581890] Lustre: lustre-MDT0000: Client 9aa84f52-4b25-4617-9114-55e69bf1cbd0 (at 192.168.201.8@tcp) reconnected, waiting for 1 clients in recovery for 0:01 [ 6894.594714] Lustre: Skipped 4 previous similar messages [ 6901.741821] Lustre: lustre-MDT0000: Recovery already passed deadline 0:05. If you do not want to wait more, you may force taget eviction via 'lctl --device lustre-MDT0000 abort_recovery. [ 6908.909495] Lustre: lustre-MDT0000: Recovery already passed deadline 0:12. If you do not want to wait more, you may force taget eviction via 'lctl --device lustre-MDT0000 abort_recovery. [ 6910.136111] LustreError: 184910:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 715 awake [ 6910.219882] Lustre: 184910:0:(ldlm_lib.c:2829:target_recovery_thread()) too long recovery - read logs [ 6910.232087] LustreError: dumping log to /tmp/lustre-log.1761245492.184910 [ 6910.318054] Lustre: lustre-OST0000: deleting orphan objects from 0x0:7340 to 0x0:7361 [ 6915.588922] Lustre: DEBUG MARKER: oleg108-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6916.661730] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6924.877143] Lustre: DEBUG MARKER: == replay-single test complete, duration 6763 sec ======== 14:51:46 (1761245506) [ 6935.008954] 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 [ 6935.037276] Lustre: Skipped 10 previous similar messages [ 6935.047873] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6935.051088] Lustre: Skipped 2 previous similar messages [ 6936.593901] Lustre: server umount lustre-MDT0000 complete [ 6936.596030] Lustre: Skipped 9 previous similar messages [ 6940.166618] LustreError: 5529:0:(ldlm_lockd.c:2526:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1761245522 with bad export cookie 2199806230093363044 [ 6940.184194] LustreError: 5529:0:(ldlm_lockd.c:2526:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 6953.105149] Lustre: DEBUG MARKER: oleg108-server.virtnet: executing unload_modules_local [ 6955.409631] Key type lgssc unregistered [ 6955.595231] LNet: 186914:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6955.612367] LNet: Removed LNI 192.168.201.108@tcp [ 6956.213307] Key type .llcrypt unregistered [ 6956.216733] Key type ._llcrypt unregistered