[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 501828964 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524588K 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.001016] APIC: Switch to symmetric I/O mode setup [ 0.002399] x2apic enabled [ 0.003018] Switched APIC routing to physical x2apic. [ 0.004021] kvm-guest: setup PV IPIs [ 0.007389] ..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.008025] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009017] pid_max: default: 32768 minimum: 301 [ 0.010178] LSM: Security Framework initializing [ 0.011091] Yama: becoming mindful. [ 0.013069] SELinux: Initializing. [ 0.014119] *** VALIDATE selinux *** [ 0.027713] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.034051] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.035342] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.037068] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.038124] *** VALIDATE tmpfs *** [ 0.039487] *** VALIDATE proc *** [ 0.041236] *** VALIDATE cgroup *** [ 0.042010] *** VALIDATE cgroup2 *** [ 0.043289] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.044165] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.045011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.046037] Spectre V2 : User space: Vulnerable [ 0.047018] Speculative Store Bypass: Vulnerable [ 0.050076] debug: unmapping init [mem 0xffffffffad459000-0xffffffffad460fff] [ 0.054625] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.056074] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.057036] ... version: 2 [ 0.058019] ... bit width: 48 [ 0.059020] ... generic registers: 4 [ 0.060024] ... value mask: 0000ffffffffffff [ 0.061025] ... max period: 00007fffffffffff [ 0.062021] ... fixed-purpose events: 3 [ 0.063023] ... event mask: 000000070000000f [ 0.064289] rcu: Hierarchical SRCU implementation. [ 0.068187] smp: Bringing up secondary CPUs ... [ 0.069782] x86: Booting SMP configuration: [ 0.070035] .... node #0, CPUs: #1 #2 #3 [ 0.084286] smp: Brought up 1 node, 4 CPUs [ 0.086021] smpboot: Max logical packages: 1 [ 0.087013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.122078] node 0 deferred pages initialised in 33ms [ 0.125323] devtmpfs: initialized [ 0.126244] x86/mm: Memory block size: 128MB [ 0.129358] gcov: version magic: 0x41383552 [ 0.131662] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.132245] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.133314] pinctrl core: initialized pinctrl subsystem [ 0.134466] [ 0.135014] ************************************************************* [ 0.136015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.137011] ** ** [ 0.138018] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.139016] ** ** [ 0.140018] ** This means that this kernel is built to expose internal ** [ 0.142007] ** IOMMU data structures, which may compromise security on ** [ 0.143014] ** your system. ** [ 0.144020] ** ** [ 0.145014] ** If you see this message and you are not debugging the ** [ 0.146010] ** kernel, report this immediately to your vendor! ** [ 0.147012] ** ** [ 0.148020] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.149021] ************************************************************* [ 0.150992] NET: Registered protocol family 16 [ 0.153820] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.158075] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.162086] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.166095] cpuidle: using governor menu [ 0.168185] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.172623] PCI: Using configuration type 1 for base access [ 0.173000] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.187165] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.188000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.189079] cryptd: max_cpu_qlen set to 1000 [ 0.191807] ACPI: Added _OSI(Module Device) [ 0.193143] ACPI: Added _OSI(Processor Device) [ 0.195017] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.197085] ACPI: Added _OSI(Processor Aggregator Device) [ 0.204076] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.213840] ACPI: Interpreter enabled [ 0.216094] ACPI: PM: (supports S0 S3 S4 S5) [ 0.218022] ACPI: Using IOAPIC for interrupt routing [ 0.221140] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.225469] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.241884] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.245055] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.249022] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.254208] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.264153] acpiphp: Slot [2] registered [ 0.266267] acpiphp: Slot [5] registered [ 0.268205] acpiphp: Slot [6] registered [ 0.269000] acpiphp: Slot [7] registered [ 0.273856] acpiphp: Slot [8] registered [ 0.276173] acpiphp: Slot [9] registered [ 0.279288] acpiphp: Slot [10] registered [ 0.282263] acpiphp: Slot [3] registered [ 0.285603] acpiphp: Slot [4] registered [ 0.291165] acpiphp: Slot [11] registered [ 0.296775] acpiphp: Slot [12] registered [ 0.302170] acpiphp: Slot [13] registered [ 0.304179] acpiphp: Slot [14] registered [ 0.308178] acpiphp: Slot [15] registered [ 0.310162] acpiphp: Slot [16] registered [ 0.311281] acpiphp: Slot [17] registered [ 0.315168] acpiphp: Slot [18] registered [ 0.320349] acpiphp: Slot [19] registered [ 0.325516] acpiphp: Slot [20] registered [ 0.330589] acpiphp: Slot [21] registered [ 0.331146] acpiphp: Slot [22] registered [ 0.334000] acpiphp: Slot [23] registered [ 0.334133] acpiphp: Slot [24] registered [ 0.338816] acpiphp: Slot [25] registered [ 0.343156] acpiphp: Slot [26] registered [ 0.346180] acpiphp: Slot [27] registered [ 0.349298] acpiphp: Slot [28] registered [ 0.351223] acpiphp: Slot [29] registered [ 0.353154] acpiphp: Slot [30] registered [ 0.355497] acpiphp: Slot [31] registered [ 0.359000] PCI host bridge to bus 0000:00 [ 0.360030] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.366026] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.371020] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.375040] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.380027] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.386027] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.391396] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.395795] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.407137] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.427027] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.437063] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.442019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.449143] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.452026] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.453629] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.455064] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.460591] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.468094] pci 0000:00:01.3: quirk_piix4_acpi+0x0/0x1e0 took 12695 usecs [ 0.476342] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.484000] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.506026] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.521017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.522000] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.547025] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.557021] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.587023] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.605362] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.614017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.622020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.637060] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.646000] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.655019] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.665016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.676039] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.708071] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.729047] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.746024] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.829042] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.869556] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.880027] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.893029] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.915038] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.940000] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.951035] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.960027] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.987060] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.997228] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.999349] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 1.001291] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 1.002244] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 1.005049] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 1.009131] iommu: Default domain type: Passthrough [ 1.011429] SCSI subsystem initialized [ 1.012122] ACPI: bus type USB registered [ 1.014105] usbcore: registered new interface driver usbfs [ 1.015085] usbcore: registered new interface driver hub [ 1.017089] usbcore: registered new device driver usb [ 1.019162] pps_core: LinuxPPS API ver. 1 registered [ 1.020009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 1.022068] PTP clock support registered [ 1.023129] EDAC MC: Ver: 3.0.0 [ 1.025101] PCI: Using ACPI for IRQ routing [ 1.027111] NetLabel: Initializing [ 1.029019] NetLabel: domain hash size = 128 [ 1.030009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.031000] NetLabel: unlabeled traffic allowed by default [ 1.031000] vgaarb: loaded [ 1.031024] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.032008] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.034188] clocksource: Switched to clocksource kvm-clock [ 1.213360] VFS: Disk quotas dquot_6.6.0 [ 1.215783] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.219237] *** VALIDATE ramfs *** [ 1.220882] *** VALIDATE hugetlbfs *** [ 1.227203] pnp: PnP ACPI init [ 1.232874] pnp: PnP ACPI: found 6 devices [ 1.311100] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.317995] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.323458] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.326200] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.328773] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.331945] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.335750] NET: Registered protocol family 2 [ 1.340181] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.346747] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.352575] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.359293] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.363412] TCP: Hash tables configured (established 65536 bind 65536) [ 1.366710] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.370726] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.375438] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.378993] NET: Registered protocol family 1 [ 1.382085] RPC: Registered named UNIX socket transport module. [ 1.384772] RPC: Registered udp transport module. [ 1.386911] RPC: Registered tcp transport module. [ 1.388876] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.391634] NET: Registered protocol family 44 [ 1.394417] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.397804] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.400862] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.406215] PCI: CLS 0 bytes, default 64 [ 1.408227] Unpacking initramfs... [ 4.750532] debug: unmapping init [mem 0xffff9938bcc54000-0xffff9938bffbffff] [ 4.756085] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 4.759496] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 4.764523] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 5.383350] Initialise system trusted keyrings [ 5.385399] Key type blacklist registered [ 5.387592] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 5.406343] zbud: loaded [ 5.410498] *** VALIDATE nfs *** [ 5.412531] *** VALIDATE nfs4 *** [ 5.415026] pstore: using deflate compression [ 5.421331] Platform Keyring initialized [ 5.626406] NET: Registered protocol family 38 [ 5.627899] Key type asymmetric registered [ 5.629381] Asymmetric key parser 'x509' registered [ 5.634685] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 5.643662] io scheduler mq-deadline registered [ 5.646224] io scheduler kyber registered [ 5.648479] io scheduler bfq registered [ 5.650691] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 5.655589] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 5.667301] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 5.679812] ACPI: Power Button [PWRF] [ 5.699227] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 5.717334] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 5.760184] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 5.771858] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 5.796090] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 5.826501] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 5.856244] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 5.861540] Non-volatile memory driver v1.3 [ 5.863418] Linux agpgart interface v0.103 [ 5.937579] virtio_blk virtio1: [vda] 145888 512-byte logical blocks (74.7 MB/71.2 MiB) [ 5.941449] vda: detected capacity change from 0 to 74694656 [ 5.970970] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 5.974177] vdb: detected capacity change from 0 to 1073741824 [ 6.011270] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.015648] vdc: detected capacity change from 0 to 2621440000 [ 6.068929] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.075496] vdd: detected capacity change from 0 to 2621440000 [ 6.109479] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.115399] vde: detected capacity change from 0 to 4294967296 [ 6.147649] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.153385] vdf: detected capacity change from 0 to 4294967296 [ 6.168782] libphy: Fixed MDIO Bus: probed [ 6.187424] usbcore: registered new interface driver usbserial_generic [ 6.191149] usbserial: USB Serial support registered for generic [ 6.194126] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 6.200128] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 6.202635] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 6.208518] mousedev: PS/2 mouse device common for all mice [ 6.217149] rtc_cmos 00:05: RTC can wake from S4 [ 6.224214] rtc_cmos 00:05: registered as rtc0 [ 6.226519] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 6.227900] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 6.234227] intel_pstate: CPU model not supported [ 6.242941] hid: raw HID events driver (C) Jiri Kosina [ 6.246101] usbcore: registered new interface driver usbhid [ 6.248083] usbhid: USB HID core driver [ 6.250991] drop_monitor: Initializing network drop monitor service [ 6.253942] Initializing XFRM netlink socket [ 6.257561] NET: Registered protocol family 10 [ 6.259274] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 6.263364] Segment Routing with IPv6 [ 6.263416] NET: Registered protocol family 17 [ 6.263689] mpls_gso: MPLS GSO support [ 6.293495] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 6.298188] RAS: Correctable Errors collector initialized. [ 6.317633] AVX version of gcm_enc/dec engaged. [ 6.321260] AES CTR mode by8 optimization enabled [ 6.539775] sched_clock: Marking stable (6539745510, 0)->(8080913487, -1541167977) [ 6.551417] registered taskstats version 1 [ 6.561571] Loading compiled-in X.509 certificates [ 6.568963] zswap: loaded using pool lzo/zbud [ 6.651632] Key type big_key registered [ 6.676711] Key type encrypted registered [ 6.678448] ima: No TPM chip found, activating TPM-bypass! [ 6.682815] ima: Allocated hash algorithm: sha1 [ 6.688406] ima: No architecture policies found [ 6.694293] evm: Initialising EVM extended attributes: [ 6.701179] evm: security.selinux [ 6.702390] evm: security.ima [ 6.704851] evm: security.capability [ 6.708371] evm: HMAC attrs: 0x1 [ 6.724157] rtc_cmos 00:05: setting system clock to 2026-08-06 23:28:01 UTC (1786058881) [ 6.733861] debug: unmapping init [mem 0xffffffffae403000-0xffffffffae5fffff] [ 6.745395] debug: unmapping init [mem 0xffffffffad182000-0xffffffffad458fff] [ 6.764524] Write protecting the kernel read-only data: 28672k [ 6.787239] debug: unmapping init [mem 0xffffffffab803000-0xffffffffab9fffff] [ 6.794087] debug: unmapping init [mem 0xffffffffac114000-0xffffffffac1fffff] [ 6.907260] 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) [ 6.930531] systemd[1]: Detected virtualization kvm. [ 6.937124] systemd[1]: Detected architecture x86-64. [ 6.938875] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 7.046515] systemd[1]: No hostname configured. [ 7.050928] systemd[1]: Set hostname to . [ 7.059202] random: systemd: uninitialized urandom read (16 bytes read) [ 7.065041] systemd[1]: Initializing machine ID from random generator. [ 7.221185] random: ln: uninitialized urandom read (6 bytes read) [ 7.555072] random: systemd: uninitialized urandom read (16 bytes read) [ 7.570675] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 7.615477] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ 7.660078] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Swap. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Timers. [ OK ] Reached target Slices. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Journal Service... [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 9.932685] device-mapper: uevent: version 1.0.3 [ 9.942451] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ 12.648737] virtio_net virtio0 ens2: renamed from eth0 [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 12.744934] random: fast init done [ 13.173442] scsi host0: ata_piix [ 13.195192] scsi host1: ata_piix [ 13.199749] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 13.211884] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 18.248457] random: crng init done [ 18.259958] random: 7 urandom warning(s) missed due to ratelimiting [ 21.018499] dracut-initqueue[583]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 23.609109] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 26.575299] printk: systemd: 26 output lines suppressed due to ratelimiting [ 27.814066] SELinux: Disabled at runtime. [ 27.964583] 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) [ 27.986551] systemd[1]: Detected virtualization kvm. [ 27.991658] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 30.351517] systemd[1]: initrd-switch-root.service: Succeeded. [ 30.373614] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 30.405941] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 30.421430] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 30.433651] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 30.450955] systemd[1]: Starting Journal Service... Starting Journal Service... [ 30.469621] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit to trigger not loaded. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting Huge Pages File System... [ OK ] Created slice system-getty.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root and Kernel File Systems... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. Mounting Kernel Debug File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on initctl Compatibility Named Pipe. Starting udev Coldplug all Devices... [ 31.068775] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting Apply Kernel Variables... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on Process Core Dump Socket. Mounting POSIX Message Queue File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Flush Journal to Persistent Storage... Starting Create Static Device Nodes in /dev... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 32.407794] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 34.310944] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 34.679545] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 35.015207] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 35.166494] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (9s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ ***] A start job is running for Configur…only root support (11s / no limit)[ 41.493419] Key type dns_resolver registered [ **] A start job is running for Configur…only root support (11s / no limit) [ *] A start job is running for Configur…only root support (12s / no limit)[ 42.315959] NFS: Registering the id_resolver key type [ 42.318974] Key type id_resolver registered [ 42.323620] Key type id_legacy registered [ **] A start job is running for Configur…only root support (12s / no limit) [ ***] A start job is running for Configur…only root support (13s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started dnf makecache --timer. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy 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 Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting System Logging Service... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg121-server login: [ 116.349178] libcfs: loading out-of-tree module taints kernel. [ 116.395423] Key type ._llcrypt registered [ 116.399533] Key type .llcrypt registered [ 116.526396] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_hostid [ 138.680604] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 140.852768] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 140.891539] alg: No test for adler32 (adler32-zlib) [ 142.703484] Lustre: Lustre: Build Version: 2.17.56_50_gf66e916 [ 144.011733] LNet: Added LNI 192.168.201.121@tcp [8/256/0/180] [ 145.919503] Key type lgssc registered [ 148.244744] Lustre: Echo OBD driver; http://www.lustre.org/ [ 170.714042] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 216.074973] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 230.103278] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 230.159854] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 231.498413] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 231.562366] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 231.752618] Lustre: lustre-MDT0000: new disk, initializing [ 231.955854] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 232.004558] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 237.644761] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 254.564535] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 254.678747] Lustre: 6515:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 254.721186] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 254.727618] Lustre: Skipped 1 previous similar message [ 254.823858] Lustre: lustre-MDT0001: new disk, initializing [ 254.900623] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 254.960868] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 254.974468] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 260.580569] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 266.753633] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 279.978822] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 280.551243] Lustre: lustre-OST0000: new disk, initializing [ 280.560490] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 280.568794] Lustre: 8456:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 280.694347] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 288.782810] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 289.305187] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 289.320210] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 289.417499] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 304.755179] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 304.956279] Lustre: lustre-OST0001: new disk, initializing [ 304.960134] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 304.964872] Lustre: 9527:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 305.036831] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 306.070032] hrtimer: interrupt took 3043621 ns [ 311.024925] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 313.402051] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 313.419098] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 313.496447] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 322.507391] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 329.214708] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 335.230782] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing check_logdir /tmp/testlogs/ [ 340.995301] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing yml_node [ 344.643463] Lustre: DEBUG MARKER: Client: 2.17.56.50 [ 347.242700] Lustre: DEBUG MARKER: MDS: 2.17.56.50 [ 349.896577] Lustre: DEBUG MARKER: OSS: 2.17.56.50 [ 351.733460] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Thu Aug 6 19:33:44 EDT 2026 [ 367.822954] Lustre: DEBUG MARKER: excepting tests: [ 377.143250] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 388.064421] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 388.088211] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 388.107635] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 390.111711] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 390.112261] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 391.624050] Lustre: server umount lustre-MDT0000 complete [ 400.077036] LustreError: 6510:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059274 with bad export cookie 14627785055523281921 [ 400.103157] LustreError: 6510:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 400.111687] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 400.351456] LustreError: 6523:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 400.355100] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 400.359974] LustreError: 6523:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 7 previous similar messages [ 400.373971] Lustre: Skipped 3 previous similar messages [ 400.425047] Lustre: server umount lustre-MDT0001 complete [ 408.684449] Lustre: server umount lustre-OST0000 complete [ 417.201661] Lustre: server umount lustre-OST0001 complete [ 434.446579] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing unload_modules_local [ 436.905635] Key type lgssc unregistered [ 437.181283] LNet: 14806:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 437.196898] LNetError: 14806:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 437.207128] LNet: Removed LNI 192.168.201.121@tcp [ 438.375273] Key type .llcrypt unregistered [ 438.377568] Key type ._llcrypt unregistered [ 462.799182] Key type ._llcrypt registered [ 462.801528] Key type .llcrypt registered [ 462.927903] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_hostid [ 478.765913] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 479.917417] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 480.045158] alg: No test for adler32 (adler32-zlib) [ 481.435467] Lustre: Lustre: Build Version: 2.17.56_50_gf66e916 [ 481.808721] LNet: Added LNI 192.168.201.121@tcp [8/256/0/180] [ 483.591206] Key type lgssc registered [ 485.240276] Lustre: Echo OBD driver; http://www.lustre.org/ [ 537.967769] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 551.581728] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 551.606063] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 553.152075] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 553.192851] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 553.296653] Lustre: lustre-MDT0000: new disk, initializing [ 553.365964] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 553.395562] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 557.754855] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 571.610618] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 571.753325] Lustre: 19262:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 571.790524] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 571.797111] Lustre: Skipped 1 previous similar message [ 571.869279] Lustre: lustre-MDT0001: new disk, initializing [ 571.939660] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 571.962772] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 571.973467] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 576.708529] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 581.849764] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 591.938356] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 592.157914] Lustre: lustre-OST0000: new disk, initializing [ 592.161456] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 592.167577] Lustre: 21200:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 592.245815] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 593.980118] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 593.995876] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 594.054591] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 599.008409] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 612.750184] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 612.919929] Lustre: lustre-OST0001: new disk, initializing [ 612.923566] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 612.934160] Lustre: 22222:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 613.019852] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 618.649745] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 621.646941] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 621.656295] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 621.753472] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 627.797355] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 639.500865] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 646.524531] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 19:38:39 (1786059519) === [ 647.952812] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 19:38:41 (1786059521) [ 665.368815] Lustre: Failing over lustre-MDT0000 [ 667.549161] Lustre: server umount lustre-MDT0000 complete [ 668.129663] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 668.140276] Lustre: Skipped 1 previous similar message [ 670.618508] Lustre: Failing over lustre-MDT0001 [ 670.621100] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059545 with bad export cookie 15772276523391818598 [ 670.621804] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 670.648022] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 670.861432] Lustre: server umount lustre-MDT0001 complete [ 678.747177] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 680.415745] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff993803795500 x1872818975408256/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 680.834853] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 680.849308] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 680.926578] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 680.957227] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 685.064554] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 686.049432] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 686.052423] LustreError: 24241:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 686.067121] Lustre: Skipped 3 previous similar messages [ 686.089238] LustreError: 24241:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 689.188817] LustreError: 24584:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 689.198749] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 689.208299] LustreError: 24584:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 690.016140] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059548/real 1786059548] req@ffff9938037c1500 x1872818975407616/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059564 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 691.231268] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059550/real 1786059550] req@ffff993803797800 x1872818975407744/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059566 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 691.255534] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 694.250901] LustreError: 24240:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 694.276332] LustreError: 24240:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 694.401335] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 694.614357] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 694.724352] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 694.755495] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 694.761889] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 695.711151] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059553/real 1786059553] req@ffff993941b21c00 x1872818975408128/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059569 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 699.712686] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 699.907621] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 699.916830] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 699.923758] Lustre: Skipped 1 previous similar message [ 699.975190] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 700.046411] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 700.046826] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 713.081557] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 19:39:46 (1786059586) [ 733.904441] Lustre: Failing over lustre-MDT0000 [ 734.156029] Lustre: server umount lustre-MDT0000 complete [ 735.712090] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 735.714650] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 735.722265] LustreError: 24241:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 735.740885] Lustre: Skipped 1 previous similar message [ 735.764253] LustreError: 24241:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 737.850108] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059612 with bad export cookie 15772276523391834908 [ 737.851499] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 737.868887] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 737.871166] Lustre: Failing over lustre-MDT0001 [ 738.101381] Lustre: server umount lustre-MDT0001 complete [ 749.384336] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 757.216077] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059615/real 1786059615] req@ffff993803f29500 x1872818975517312/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059631 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 757.273056] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 757.289260] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 757.341360] Lustre: Skipped 2 previous similar messages [ 761.439781] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059620/real 1786059620] req@ffff993908394000 x1872818975517952/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059636 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 761.474163] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 762.705022] LustreError: 25247:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 762.793618] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 762.849405] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 767.839654] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 771.621040] Lustre: 16423:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059630/real 1786059630] req@ffff993803f28700 x1872818975519232/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059646 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 771.671252] Lustre: 16423:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 776.163712] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 776.171823] Lustre: Skipped 2 previous similar messages [ 776.590983] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 776.974423] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 777.031879] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 777.175572] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 777.179957] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 781.825354] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 782.317575] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 782.321906] Lustre: Skipped 1 previous similar message [ 782.343781] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 782.371504] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 782.371672] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 785.922494] Lustre: *** cfs_fail_loc=193, val=0*** [ 790.331828] Lustre: Failing over lustre-MDT0000 [ 790.580375] Lustre: server umount lustre-MDT0000 complete [ 792.543826] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 792.551144] 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 [ 792.553455] LustreError: 26627:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 792.553467] LustreError: 26627:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 9 previous similar messages [ 792.609475] Lustre: Skipped 4 previous similar messages [ 799.682773] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 799.821475] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 800.135270] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 800.146221] Lustre: Skipped 1 previous similar message [ 800.183957] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 804.519737] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 805.348728] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 805.358498] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 805.367769] Lustre: Skipped 2 previous similar messages [ 805.404409] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 805.491436] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 805.498271] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 814.539353] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 19:41:27 (1786059687) [ 829.430184] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 849.088877] Lustre: 30505:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 874.048541] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 877.612219] Lustre: 31641:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 891.156355] Lustre: *** cfs_fail_loc=198, val=0*** [ 903.643752] Lustre: Failing over lustre-MDT0000 [ 903.984852] Lustre: server umount lustre-MDT0000 complete [ 907.744479] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 907.752708] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 907.753573] LustreError: 26627:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 907.768681] Lustre: Skipped 3 previous similar messages [ 907.783607] LustreError: 26627:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 9 previous similar messages [ 908.037104] LustreError: 31668:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059782 with bad export cookie 15772276523391863622 [ 908.040934] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 908.047585] Lustre: Failing over lustre-MDT0001 [ 908.047750] LustreError: 31668:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 908.571570] Lustre: server umount lustre-MDT0001 complete [ 914.368614] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 919.804551] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 929.018498] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 929.247239] Lustre: 16422:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059788/real 1786059788] req@ffff9939373a1f80 x1872818975689984/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059804 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 929.247976] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 929.270823] Lustre: 16422:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 929.278929] Lustre: Skipped 1 previous similar message [ 932.384430] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9939373a3b80 x1872818975691648/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 932.784087] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 932.810258] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 937.660793] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 946.558236] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 946.782216] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 946.979114] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 946.992229] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 948.979102] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 949.001099] Lustre: Skipped 3 previous similar messages [ 949.029528] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 949.079897] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 949.132200] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 949.136084] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 952.047333] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 964.638715] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 19:43:58 (1786059838) [ 983.285973] Lustre: Failing over lustre-MDT0000 [ 983.588869] Lustre: server umount lustre-MDT0000 complete [ 985.059191] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 985.061836] 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 [ 985.072970] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 985.085247] Lustre: Skipped 2 previous similar messages [ 985.110691] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 13 previous similar messages [ 986.508714] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059861 with bad export cookie 15772276523391890796 [ 986.509892] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 986.511860] Lustre: Failing over lustre-MDT0001 [ 986.515651] LustreError: 19253:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 986.724683] Lustre: server umount lustre-MDT0001 complete [ 990.811706] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 995.175331] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1004.192436] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1004.295554] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 1005.535770] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786059864/real 1786059864] req@ffff993936dcad80 x1872818975814912/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786059880 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1005.570253] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 1011.745303] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff993941ab1180 x1872818975817344/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1012.256969] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1017.974905] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1024.493242] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1024.504634] Lustre: Skipped 4 previous similar messages [ 1027.420885] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1027.469823] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1027.631127] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1027.740519] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:233 to 0x2c0000400:257) [ 1027.744369] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 1032.592995] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1033.196529] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1033.239826] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1033.316640] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1033.319760] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 1057.400204] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 1074.431807] Lustre: 38941:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1097.153879] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1100.690655] Lustre: 40076:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1119.714724] Lustre: Failing over lustre-MDT0000 [ 1119.902867] Lustre: server umount lustre-MDT0000 complete [ 1120.224769] 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 [ 1120.225612] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1120.230445] LustreError: 21194:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1120.230461] LustreError: 21194:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 10 previous similar messages [ 1120.234470] Lustre: Skipped 5 previous similar messages [ 1124.107778] Lustre: Failing over lustre-MDT0001 [ 1124.112675] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786059998 with bad export cookie 15772276523391918782 [ 1124.115615] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1124.122210] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1124.492703] Lustre: server umount lustre-MDT0001 complete [ 1129.119833] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1138.307699] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1141.727230] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786060000/real 1786060000] req@ffff99393df8f800 x1872818975960576/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786060016 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1141.778347] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1151.201809] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1151.239563] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1168.417303] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99393cdc3480 x1872818975963904/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1168.856095] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1168.858888] Lustre: Skipped 3 previous similar messages [ 1168.915150] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1173.544375] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1182.002884] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1182.072341] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1182.177740] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 1182.353174] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:297 to 0x2c0000400:321) [ 1182.354697] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:298 to 0x280000400:321) [ 1186.133938] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1186.407486] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1186.431974] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1186.446795] Lustre: Skipped 4 previous similar messages [ 1186.488431] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1186.542247] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1186.545167] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 1209.143231] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 1227.531971] Lustre: 44783:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1252.843614] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1257.233656] Lustre: 45920:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1280.021103] Lustre: Failing over lustre-MDT0000 [ 1280.243351] Lustre: server umount lustre-MDT0000 complete [ 1283.358442] Lustre: Failing over lustre-MDT0001 [ 1283.359143] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786060158 with bad export cookie 15772276523391946348 [ 1283.359711] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1283.385547] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1283.570961] Lustre: server umount lustre-MDT0001 complete [ 1288.689573] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1295.879686] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1299.407253] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786060158/real 1786060158] req@ffff99393e560380 x1872818976105344/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786060174 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1299.447782] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1299.455489] 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 [ 1299.471956] Lustre: Skipped 3 previous similar messages [ 1306.918478] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1306.952536] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1308.705969] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99393e562a00 x1872818976108416/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1309.083956] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1310.071373] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1310.085140] Lustre: Skipped 4 previous similar messages [ 1313.936675] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1322.002196] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1322.036606] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1322.186692] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1322.191039] LustreError: Skipped 1 previous similar message [ 1322.290962] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1322.294775] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:361 to 0x2c0000400:385) [ 1326.072722] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1327.594110] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1327.643049] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1327.708845] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 1327.719336] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 1340.493224] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 19:50:13 (1786060213) [ 1356.188667] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 1374.342551] Lustre: 50630:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1395.966969] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1417.292386] Lustre: Failing over lustre-MDT0000 [ 1419.589443] Lustre: server umount lustre-MDT0000 complete [ 1419.746516] LustreError: 25247:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1419.771178] LustreError: 25247:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 21 previous similar messages [ 1422.879203] LustreError: 19254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786060297 with bad export cookie 15772276523391973914 [ 1422.886935] Lustre: Failing over lustre-MDT0001 [ 1422.887507] LustreError: 19254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1422.887787] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1423.347796] Lustre: server umount lustre-MDT0001 complete [ 1428.739969] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1440.870205] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1451.449511] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1460.144365] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1471.720370] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1471.738651] Lustre: lustre-MDT0000: reset Object Index mappings [ 1492.455587] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9939035e4a80 x1872818976259072/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1492.947627] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1492.954531] Lustre: Skipped 3 previous similar messages [ 1492.999212] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1497.105667] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1505.509833] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1505.534779] Lustre: lustre-MDT0001: reset Object Index mappings [ 1505.889192] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:426 to 0x2c0000400:449) [ 1505.895210] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:425 to 0x280000400:449) [ 1509.748924] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1509.986095] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1509.993527] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1510.003817] Lustre: Skipped 4 previous similar messages [ 1510.033343] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1510.061075] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1510.061309] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 1519.541712] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 19:53:12 (1786060392) [ 1530.864934] LustreError: 51785:0:(client.c:1381:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff99393ca33480 x1872818976348672/t0(0) o104->lustre-OST0001@192.168.201.21@tcp:15/16 lens 328/224 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'' uid:4294967295 gid:4294967295 projid:4294967295 [ 1537.719526] Lustre: Failing over lustre-MDT0000 [ 1537.955790] Lustre: server umount lustre-MDT0000 complete [ 1540.805548] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786060415 with bad export cookie 15772276523392001480 [ 1540.808703] Lustre: Failing over lustre-MDT0001 [ 1540.809237] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1540.819222] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 1541.011690] Lustre: server umount lustre-MDT0001 complete [ 1545.293320] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1554.083205] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1558.496982] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786060417/real 1786060417] req@ffff99393e61a680 x1872818976364032/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786060433 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1558.500208] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1558.532115] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 1558.550480] Lustre: Skipped 14 previous similar messages [ 1561.994930] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1572.518505] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1583.856843] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1583.876380] Lustre: lustre-MDT0000: reset Object Index mappings [ 1586.015188] LustreError: 58322:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 1586.027793] LustreError: 58322:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff99393e619180 x1872818976366080/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786060460 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1586.044479] LustreError: 58322:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 1586.507441] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1591.183853] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1598.712338] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1598.731546] Lustre: lustre-MDT0001: reset Object Index mappings [ 1598.871098] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1598.882641] LustreError: Skipped 1 previous similar message [ 1599.005381] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1599.008122] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:489 to 0x2c0000400:513) [ 1602.664086] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1603.044648] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1603.079450] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1603.116461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1603.116589] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:521 to 0x2c0000401:545) [ 1608.066928] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32040: rc = 0 [ 1609.241711] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/64029 with flags 0x52: rc = 0 [ 1629.526299] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 19:55:02 (1786060502) [ 1647.954335] Lustre: Failing over lustre-MDT0000 [ 1648.463342] Lustre: server umount lustre-MDT0000 complete [ 1651.806631] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786060526 with bad export cookie 15772276523392028871 [ 1651.811369] Lustre: Failing over lustre-MDT0001 [ 1651.825373] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1652.090746] Lustre: server umount lustre-MDT0001 complete [ 1657.539608] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1667.060968] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1676.953931] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1688.999488] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1702.691830] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1702.743567] Lustre: lustre-MDT0000: reset Object Index mappings [ 1722.849672] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99393cd7c700 x1872818976492544/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1723.427622] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1729.604355] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1738.222720] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1738.244526] Lustre: lustre-MDT0001: reset Object Index mappings [ 1738.729189] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1738.733142] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1740.705121] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1740.759834] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1740.827784] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 1740.829535] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:585 to 0x2c0000401:609) [ 1743.598414] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1751.500221] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32028: rc = 0 [ 1754.722955] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32017 with flags 0x52: rc = 0 [ 1877.877748] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 19:59:10 (1786060750) [ 1918.106898] Lustre: Failing over lustre-MDT0000 [ 1918.908639] Lustre: server umount lustre-MDT0000 complete [ 1922.859633] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786060797 with bad export cookie 15772276523392056689 [ 1922.872542] Lustre: Failing over lustre-MDT0001 [ 1922.873800] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1922.873814] LustreError: Skipped 1 previous similar message [ 1922.898265] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1923.522272] Lustre: server umount lustre-MDT0001 complete [ 1930.238451] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1940.699914] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1949.911206] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1960.813580] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1973.063953] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1973.080265] Lustre: lustre-MDT0000: reset Object Index mappings [ 1993.144512] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1993.189080] LustreError: 21193:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 23 previous similar messages [ 1993.365861] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1998.636234] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2008.415115] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2008.457225] Lustre: lustre-MDT0001: reset Object Index mappings [ 2008.937444] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2008.940382] Lustre: Skipped 6 previous similar messages [ 2008.971552] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:617 to 0x2c0000400:641) [ 2008.975082] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 2012.001445] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2012.005045] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2012.016770] Lustre: Skipped 14 previous similar messages [ 2012.067232] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2012.169222] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2012.179212] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:649 to 0x2c0000401:673) [ 2015.194956] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2026.103545] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32035: rc = 0 [ 2029.390823] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2116.696524] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 20:03:09 (1786060989) [ 2129.778156] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2129.782881] Lustre: Skipped 1 previous similar message [ 2130.288949] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2130.295823] Lustre: Skipped 31 previous similar messages [ 2131.308955] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2131.313917] Lustre: Skipped 181 previous similar messages [ 2152.084912] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 20:03:44 (1786061024) [ 2157.133335] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2157.135176] Lustre: Skipped 241 previous similar messages [ 2173.324491] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 20:04:06 (1786061046) [ 2201.576875] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2201.609504] LustreError: Skipped 4 previous similar messages [ 2201.622994] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2201.674385] Lustre: Skipped 12 previous similar messages [ 2201.694677] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2202.594184] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2207.715259] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2207.718029] Lustre: Skipped 6 previous similar messages [ 2212.833397] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2212.849795] Lustre: Skipped 3 previous similar messages [ 2213.349717] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2213.938543] Lustre: server umount lustre-MDT0000 complete [ 2218.800040] LustreError: 19254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786061093 with bad export cookie 15772276523392100894 [ 2218.800612] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2218.806228] LustreError: 19254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2223.075408] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2223.081467] Lustre: Skipped 1 previous similar message [ 2233.312677] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2233.618538] Lustre: server umount lustre-MDT0001 complete [ 2252.255187] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2252.515566] Lustre: server umount lustre-OST0000 complete [ 2262.835681] Lustre: server umount lustre-OST0001 complete [ 2271.013670] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_hostid [ 2282.973610] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 2343.029896] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 2357.520665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2357.937894] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2357.993286] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2358.209527] Lustre: lustre-MDT0000: new disk, initializing [ 2358.385336] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2364.327874] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2376.778511] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2376.961948] Lustre: 75841:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2376.983440] Lustre: 75841:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2377.017790] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2377.028735] Lustre: Skipped 1 previous similar message [ 2377.217311] Lustre: lustre-MDT0001: new disk, initializing [ 2377.437768] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2377.459677] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2383.487534] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2389.166284] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2395.835223] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2396.109992] Lustre: lustre-OST0000: new disk, initializing [ 2396.123733] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2396.133442] Lustre: 77476:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2397.963280] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2397.989415] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2398.088394] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2402.859756] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2415.437186] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2415.726992] Lustre: lustre-OST0001: new disk, initializing [ 2415.736327] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2415.745471] Lustre: 78347:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2417.167326] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2417.181722] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2417.354918] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2423.457247] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2435.249301] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2440.203633] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2470.813072] Lustre: Failing over lustre-MDT0000 [ 2471.155970] LustreError: 79353:0:(ldlm_resource.c:1207:ldlm_resource_complain()) MGS: namespace resource [0x65727473756c:0x0:0x0].0x0 (ffff993926be8900) refcount nonzero (2) after lock cleanup; forcing cleanup. [ 2471.370608] Lustre: server umount lustre-MDT0000 complete [ 2475.386886] Lustre: Failing over lustre-MDT0001 [ 2475.853552] Lustre: server umount lustre-MDT0001 complete [ 2483.324623] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2493.389719] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2494.880410] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786061353/real 1786061353] req@ffff99393b5c2300 x1872818977028736/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786061369 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2494.919266] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 30 previous similar messages [ 2501.142544] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2512.049670] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2524.770270] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2524.788692] Lustre: lustre-MDT0000: reset Object Index mappings [ 2546.144906] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xdae261eed406a3e9 [ 2546.174045] Lustre: MGC192.168.201.121@tcp: Connection restored to 0@lo (at 0@lo) [ 2546.184535] Lustre: Skipped 4 previous similar messages [ 2546.806922] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2553.051982] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2565.728874] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2566.010594] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2566.033483] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 2571.278478] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2571.368388] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2571.496150] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 2571.497168] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2572.894756] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2584.198639] Lustre: *** cfs_fail_loc=190, val=3*** [ 2584.200387] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32007: rc = 0 [ 2585.302038] Lustre: *** cfs_fail_loc=190, val=3*** [ 2585.318917] Lustre: Skipped 1 previous similar message [ 2586.387895] Lustre: *** cfs_fail_loc=190, val=3*** [ 2587.572573] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 2589.407243] Lustre: *** cfs_fail_loc=190, val=3*** [ 2589.409625] Lustre: Skipped 2 previous similar messages [ 2593.695117] Lustre: *** cfs_fail_loc=190, val=3*** [ 2593.700737] Lustre: Skipped 2 previous similar messages [ 2600.485988] Lustre: Failing over lustre-MDT0000 [ 2600.870234] Lustre: server umount lustre-MDT0000 complete [ 2601.953852] LustreError: 81721:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2601.976402] LustreError: 81721:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 28 previous similar messages [ 2605.599703] Lustre: Failing over lustre-MDT0001 [ 2606.088713] Lustre: server umount lustre-MDT0001 complete [ 2617.639220] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2631.583539] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99380af01f80 x1872818977071616/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2632.024758] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2632.031311] Lustre: Skipped 6 previous similar messages [ 2638.984423] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2652.467123] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2653.297076] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:97) [ 2653.302701] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 2657.556339] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2658.377561] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 2658.381695] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2664.294865] Lustre: Failing over lustre-MDT0000 [ 2664.555310] Lustre: server umount lustre-MDT0000 complete [ 2669.054062] Lustre: Failing over lustre-MDT0001 [ 2669.393574] Lustre: server umount lustre-MDT0001 complete [ 2680.254772] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2680.341353] Lustre: *** cfs_fail_loc=190, val=3*** [ 2680.344187] Lustre: Skipped 2 previous similar messages [ 2698.463189] Lustre: *** cfs_fail_loc=190, val=3*** [ 2698.465144] Lustre: Skipped 5 previous similar messages [ 2702.250652] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2713.906504] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2714.157863] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 2714.159681] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:129) [ 2719.330045] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:129) [ 2719.330174] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2720.250294] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2731.095903] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 2731.129824] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/149: rc = 0 [ 2741.906354] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 20:13:34 (1786061614) [ 2775.489613] Lustre: Failing over lustre-MDT0000 [ 2775.530670] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2775.547036] Lustre: Skipped 4 previous similar messages [ 2776.308104] Lustre: server umount lustre-MDT0000 complete [ 2782.194089] Lustre: Failing over lustre-MDT0001 [ 2782.195365] LustreError: 75833:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786061656 with bad export cookie 15772276523392217416 [ 2782.197054] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2782.197061] LustreError: Skipped 3 previous similar messages [ 2782.241740] LustreError: 75833:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 2782.828364] Lustre: server umount lustre-MDT0001 complete [ 2789.365480] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2799.678704] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2802.143445] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2802.153307] Lustre: Skipped 27 previous similar messages [ 2808.041311] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2817.892493] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2830.019972] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2830.059685] Lustre: lustre-MDT0000: reset Object Index mappings [ 2830.066100] Lustre: Skipped 1 previous similar message [ 2856.474843] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2865.253194] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2865.421683] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2865.432166] LustreError: Skipped 5 previous similar messages [ 2865.671239] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2865.688234] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2870.876376] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 2870.877174] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2871.257765] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2882.530348] Lustre: *** cfs_fail_loc=190, val=2*** [ 2882.530777] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32005: rc = 0 [ 2882.531923] Lustre: Skipped 14 previous similar messages [ 2884.785728] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32006 with flags 0x52: rc = 0 [ 2911.049860] Lustre: Failing over lustre-MDT0000 [ 2911.376613] Lustre: server umount lustre-MDT0000 complete [ 2916.178324] Lustre: Failing over lustre-MDT0001 [ 2916.825525] Lustre: server umount lustre-MDT0001 complete [ 2930.989508] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2947.008555] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2949.343223] Lustre: *** cfs_fail_loc=190, val=3*** [ 2949.346643] Lustre: Skipped 29 previous similar messages [ 2955.878729] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2956.336478] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2956.358362] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2960.866620] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2961.467387] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:225) [ 2961.468327] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 2978.223426] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 20:17:31 (1786061851) [ 2992.229573] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 3010.839558] Lustre: 96378:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3037.743705] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3042.128716] Lustre: 97514:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3079.611746] Lustre: Failing over lustre-MDT0000 [ 3079.886295] Lustre: server umount lustre-MDT0000 complete [ 3083.532408] Lustre: Failing over lustre-MDT0001 [ 3083.853696] Lustre: server umount lustre-MDT0001 complete [ 3088.758561] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3099.449472] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3101.151468] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786061959/real 1786061959] req@ffff993939188700 x1872818977422464/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786061975 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3101.196202] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 58 previous similar messages [ 3110.751942] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3121.971518] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3134.648610] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3134.664440] Lustre: lustre-MDT0000: reset Object Index mappings [ 3134.666880] Lustre: Skipped 1 previous similar message [ 3153.376541] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99393918b100 x1872818977426816/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3153.813360] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3153.818664] Lustre: Skipped 4 previous similar messages [ 3158.192185] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3165.828138] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3166.154419] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3166.179993] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 3170.693256] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3171.238398] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3171.242094] Lustre: Skipped 25 previous similar messages [ 3171.316727] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 3171.317879] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 3178.345254] Lustre: *** cfs_fail_loc=190, val=3*** [ 3178.345536] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32037: rc = 0 [ 3178.347311] Lustre: Skipped 9 previous similar messages [ 3178.366033] Lustre: Skipped 2 previous similar messages [ 3181.747236] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32036 with flags 0x52: rc = 0 [ 3201.216901] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 20:21:14 (1786062074) [ 3242.592768] Lustre: Failing over lustre-MDT0000 [ 3242.991050] LustreError: 100402:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3243.004533] LustreError: 100402:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 61 previous similar messages [ 3243.154117] Lustre: server umount lustre-MDT0000 complete [ 3248.517278] Lustre: Failing over lustre-MDT0001 [ 3248.846838] Lustre: server umount lustre-MDT0001 complete [ 3256.404356] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3267.319742] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3276.029958] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3287.283149] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3299.822809] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3319.272495] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3319.281331] Lustre: Skipped 9 previous similar messages [ 3324.336379] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3332.849359] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3333.223238] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 3333.225883] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:329 to 0x280000400:353) [ 3337.590328] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3338.208868] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3338.212301] Lustre: Skipped 5 previous similar messages [ 3338.232355] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3338.244900] Lustre: Skipped 5 previous similar messages [ 3338.294761] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3338.295225] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 3384.010405] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 20:24:16 (1786062256) [ 3399.761039] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 3421.446248] Lustre: 109054:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3445.281475] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3448.579863] Lustre: 110189:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3570.112537] Lustre: Failing over lustre-MDT0000 [ 3570.783364] Lustre: server umount lustre-MDT0000 complete [ 3573.732725] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3573.744061] LustreError: Skipped 4 previous similar messages [ 3573.747825] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3573.765921] Lustre: Skipped 17 previous similar messages [ 3574.418138] LustreError: 77475:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786062449 with bad export cookie 15772276523392399983 [ 3574.425238] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3574.427245] LustreError: 77475:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 3574.437246] LustreError: Skipped 3 previous similar messages [ 3574.439853] Lustre: Failing over lustre-MDT0001 [ 3574.756663] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3574.761292] Lustre: Skipped 3 previous similar messages [ 3575.310385] Lustre: server umount lustre-MDT0001 complete [ 3581.157370] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3594.491251] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3609.841510] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3624.224246] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3640.040573] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3644.391546] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xdae261eed40cadd1 [ 3651.371494] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3660.776291] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3660.795387] Lustre: lustre-MDT0001: reset Object Index mappings [ 3660.800370] Lustre: Skipped 4 previous similar messages [ 3661.370967] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 3661.383995] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:393 to 0x280000400:417) [ 3665.596267] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3665.599625] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 3666.349541] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3736.268368] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 20:30:08 (1786062608) [ 3751.719994] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 3770.435779] Lustre: 117003:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3794.396547] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3798.578453] Lustre: 118138:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3935.941549] Lustre: Failing over lustre-MDT0000 [ 3936.444868] Lustre: server umount lustre-MDT0000 complete [ 3936.746913] LustreError: 113107:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3936.766508] LustreError: 113107:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 18 previous similar messages [ 3942.030655] Lustre: Failing over lustre-MDT0001 [ 3942.865614] Lustre: server umount lustre-MDT0001 complete [ 3951.169196] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3960.363395] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3962.335573] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786062821/real 1786062821] req@ffff993931e4a680 x1872818978010752/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786062837 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3962.364459] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 3968.709136] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3978.447264] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3990.738321] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4011.889023] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4011.894622] Lustre: Skipped 3 previous similar messages [ 4011.931308] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4011.957368] Lustre: Skipped 2 previous similar messages [ 4016.189709] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4016.996045] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4017.000738] Lustre: Skipped 15 previous similar messages [ 4024.929459] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4025.332378] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 4025.333022] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 4030.434568] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4030.461473] Lustre: Skipped 1 previous similar message [ 4030.542142] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4030.563995] Lustre: Skipped 1 previous similar message [ 4030.653346] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 4030.656748] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 4031.852897] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4040.922843] Lustre: *** cfs_fail_loc=190, val=1*** [ 4040.922932] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32046: rc = 0 [ 4040.925463] Lustre: Skipped 45 previous similar messages [ 4044.183331] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 4051.214826] Lustre: Failing over lustre-MDT0000 [ 4051.541703] Lustre: server umount lustre-MDT0000 complete [ 4054.880484] Lustre: Failing over lustre-MDT0001 [ 4055.336549] Lustre: server umount lustre-MDT0001 complete [ 4063.652828] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4064.735255] LustreError: 122945:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 4064.754621] LustreError: 122945:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff99380a217b80 x1872818978047872/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786062939 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_03.0' uid:0 gid:0 projid:4294967295 [ 4064.791869] LustreError: 122945:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 4071.094559] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4080.143153] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4080.630095] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 4080.637856] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 4085.393814] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4085.871824] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:513) [ 4085.883940] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 4092.795427] Lustre: Failing over lustre-MDT0000 [ 4093.367422] Lustre: server umount lustre-MDT0000 complete [ 4098.343354] Lustre: Failing over lustre-MDT0001 [ 4098.858250] Lustre: server umount lustre-MDT0001 complete [ 4110.393859] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4128.344460] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4137.669690] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4138.103196] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 4138.106996] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 4143.180749] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:545) [ 4143.181935] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:545) [ 4143.280292] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4158.807472] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 20:37:12 (1786063032) [ 4173.747352] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 4190.528469] Lustre: 128071:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4216.761866] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4246.948211] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 20:38:39 (1786063119) [ 4252.678696] Lustre: *** cfs_fail_loc=195, val=0*** [ 4257.108384] Lustre: Failing over lustre-OST0000 [ 4257.263719] Lustre: server umount lustre-OST0000 complete [ 4260.835168] 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 [ 4260.837367] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4260.863622] Lustre: Skipped 23 previous similar messages [ 4260.887120] LustreError: Skipped 5 previous similar messages [ 4267.207370] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4274.834957] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4466.418767] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 20:42:19 (1786063339) [ 4469.345957] Lustre: *** cfs_fail_loc=196, val=0*** [ 4469.351054] Lustre: Skipped 63 previous similar messages [ 4474.117727] Lustre: Failing over lustre-OST0000 [ 4474.322775] Lustre: server umount lustre-OST0000 complete [ 4484.370037] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4491.124530] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4679.462975] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 20:45:52 (1786063552) [ 4685.034752] Lustre: *** cfs_fail_loc=196, val=0*** [ 4685.036554] Lustre: Skipped 63 previous similar messages [ 4687.425101] Lustre: *** cfs_fail_loc=196, val=0*** [ 4687.438745] Lustre: Skipped 191 previous similar messages [ 4691.598836] Lustre: *** cfs_fail_loc=196, val=0*** [ 4691.601424] Lustre: Skipped 383 previous similar messages [ 4702.538943] Lustre: Failing over lustre-OST0000 [ 4702.665970] Lustre: server umount lustre-OST0000 complete [ 4704.742522] LustreError: 97534:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4704.762496] LustreError: 97534:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 51 previous similar messages [ 4714.075445] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4714.401785] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4714.427967] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4714.439777] Lustre: Skipped 4 previous similar messages [ 4716.327972] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4716.342892] Lustre: Skipped 4 previous similar messages [ 4716.358281] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4716.359233] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4716.363960] Lustre: Skipped 18 previous similar messages [ 4716.376494] Lustre: Skipped 4 previous similar messages [ 4720.869083] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4731.877693] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4731.888730] Lustre: Skipped 1 previous similar message [ 4733.293440] Lustre: server umount lustre-MDT0000 complete [ 4737.200945] LustreError: 75833:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786063611 with bad export cookie 15772276523393313483 [ 4737.201754] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4737.213146] LustreError: 75833:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 4737.239263] LustreError: Skipped 3 previous similar messages [ 4737.747598] Lustre: server umount lustre-MDT0001 complete [ 4752.015313] Lustre: server umount lustre-OST0000 complete [ 4765.794081] Lustre: server umount lustre-OST0001 complete [ 4774.916861] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 20:47:28 (1786063648) [ 4791.155891] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_hostid [ 4798.896035] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 4838.282727] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 4847.254450] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4847.461578] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4847.479725] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4847.540531] Lustre: lustre-MDT0000: new disk, initializing [ 4847.598248] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4847.605910] Lustre: Skipped 7 previous similar messages [ 4847.646740] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4852.589687] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4865.665098] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4865.800636] Lustre: 139388:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 4865.816064] Lustre: 139388:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4865.853278] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4865.864182] Lustre: Skipped 1 previous similar message [ 4866.002589] Lustre: lustre-MDT0001: new disk, initializing [ 4866.220934] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4866.251349] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4872.354792] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4876.264739] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4882.827887] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4883.054494] Lustre: lustre-OST0000: new disk, initializing [ 4883.059528] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4883.065415] Lustre: 141017:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4884.812071] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4884.815868] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4884.895459] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4889.002155] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4899.965607] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4900.109409] Lustre: lustre-OST0001: new disk, initializing [ 4900.117269] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4900.123930] Lustre: 141890:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4901.620892] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4901.626328] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4901.730554] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4906.340903] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4914.898972] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4918.260236] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4935.420189] Lustre: Failing over lustre-MDT0000 [ 4935.662913] Lustre: server umount lustre-MDT0000 complete [ 4937.696648] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4937.702115] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4937.706409] LustreError: Skipped 3 previous similar messages [ 4937.730099] Lustre: Skipped 10 previous similar messages [ 4938.636512] Lustre: Failing over lustre-MDT0001 [ 4938.836826] Lustre: server umount lustre-MDT0001 complete [ 4944.312912] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4952.772506] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4959.199519] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786063817/real 1786063817] req@ffff99380a1b8000 x1872818978612480/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786063833 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4959.240564] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 4960.099037] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4968.894461] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4979.299530] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4979.314274] Lustre: lustre-MDT0000: reset Object Index mappings [ 4979.319247] Lustre: Skipped 2 previous similar messages [ 4983.844115] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xdae261eed4197cf6 [ 4987.810343] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4996.451455] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4996.689131] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 4996.696357] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 5000.728503] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5001.833219] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 5001.839269] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 5052.133742] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 20:52:05 (1786063925) [ 5064.355566] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 5081.726171] Lustre: 150153:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5105.068692] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5109.782469] Lustre: 151290:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5133.015951] Lustre: Failing over lustre-MDT0000 [ 5133.036983] Lustre: *** cfs_fail_loc=199, val=0*** [ 5133.043033] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5133.055534] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5133.067399] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5133.077207] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5133.085902] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5133.100758] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5133.115917] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5133.126680] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5133.135098] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5133.144543] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5133.152271] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5133.161614] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5133.170463] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5133.176462] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5133.184352] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5133.191982] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5133.199301] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5133.206615] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5133.215643] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5133.227184] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5133.234401] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5133.241288] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5133.248514] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5133.263076] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5133.273644] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5133.281749] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5133.292508] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5133.299164] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5133.306888] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5133.320029] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5133.326753] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5133.335064] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5133.341279] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5133.351343] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5133.359222] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5133.365704] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5133.371421] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5133.376507] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5133.382270] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5133.386818] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5133.393951] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5133.399825] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5133.407378] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5133.417866] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5133.425495] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5133.445248] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5133.452794] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5133.465131] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5133.471237] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5133.477761] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5133.484347] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5133.490550] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5133.500902] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5133.512174] Lustre: 151626:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5133.821947] Lustre: server umount lustre-MDT0000 complete [ 5137.185944] Lustre: Failing over lustre-MDT0001 [ 5137.194522] Lustre: *** cfs_fail_loc=199, val=0*** [ 5137.199111] Lustre: Skipped 53 previous similar messages [ 5137.201401] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5137.209441] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5137.216749] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5137.226660] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5137.236838] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5137.248597] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5137.257926] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5137.266923] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5137.280860] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5137.287820] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5137.300827] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5137.330210] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5137.359718] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5137.376487] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5137.388700] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5137.403923] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5137.417359] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5137.431488] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5137.449826] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5137.459875] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5137.474564] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5137.486880] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5137.507194] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5137.518653] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5137.533673] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5137.548210] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5137.564730] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5137.578413] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5137.589961] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5137.602841] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5137.614900] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5137.630404] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5137.643617] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5137.651677] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5137.659235] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5137.667452] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5137.676537] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5137.697289] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5137.708467] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5137.716366] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5137.733574] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5137.740985] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5137.751291] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5137.761236] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5137.768807] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5137.777407] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5137.787611] Lustre: 151828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5138.197474] Lustre: server umount lustre-MDT0001 complete [ 5149.073483] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5149.206060] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5149.228266] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5149.241532] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5149.259484] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5149.290432] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5149.316440] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5149.330602] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5149.357623] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5149.368122] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5149.375392] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5149.392508] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5149.411689] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5149.421971] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5149.445790] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5149.469901] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5149.490689] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5149.509207] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5149.525621] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5149.548281] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5149.571139] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5149.595612] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5149.606836] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5149.618700] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5149.632807] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5149.653261] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5149.671324] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5149.687770] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5149.722180] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5149.733969] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5149.756323] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5149.770392] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5149.785424] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5149.797717] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5149.811247] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5149.823885] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5149.836880] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5149.858989] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5149.883672] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5149.910123] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5149.933971] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5149.949747] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5149.968786] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5149.989707] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5150.013163] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5150.032639] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5150.056197] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5150.071192] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5150.078736] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5150.087321] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5150.103419] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5150.114504] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5150.121939] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5150.131459] Lustre: 152326:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5161.442960] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xdae261eed419f18e [ 5166.040350] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5177.198584] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5177.264264] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5177.281883] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5177.297527] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5177.312982] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5177.353891] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5177.376194] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5177.405706] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5177.443670] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5177.460714] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5177.477263] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5177.502267] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5177.514800] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5177.530028] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5177.541486] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5177.552141] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5177.571885] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5177.582945] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5177.617772] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5177.630509] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5177.656130] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5177.686957] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5177.711552] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5177.734061] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5177.740990] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5177.749772] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5177.761996] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5177.779874] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5177.792531] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5177.803787] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5177.822785] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5177.850647] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5177.868318] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5177.887793] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5177.902180] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5177.937171] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5177.955483] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5177.981506] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5178.007431] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5178.034064] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5178.057868] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5178.070157] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5178.082749] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5178.093196] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5178.124582] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5178.142694] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5178.154946] Lustre: 153074:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5178.479316] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 5178.479685] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 5183.618776] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 5183.626347] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5184.410783] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5195.567457] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 20:54:28 (1786064068) [ 5196.653210] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5196.656173] Lustre: Skipped 123 previous similar messages [ 5198.575308] Lustre: Failing over lustre-MDT0000 [ 5198.865958] Lustre: server umount lustre-MDT0000 complete [ 5217.239812] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5222.481696] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5222.989274] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 5222.989274] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5226.864911] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 20:54:59 (1786064099) [ 5228.082865] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5229.804841] Lustre: Failing over lustre-MDT0000 [ 5230.181429] Lustre: server umount lustre-MDT0000 complete [ 5246.552633] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5251.663962] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5252.169352] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5252.169623] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 5255.678341] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 20:55:28 (1786064128) [ 5276.035548] Lustre: Failing over lustre-MDT0000 [ 5276.352812] Lustre: server umount lustre-MDT0000 complete [ 5280.008510] Lustre: Failing over lustre-MDT0001 [ 5280.247866] Lustre: server umount lustre-MDT0001 complete [ 5289.425681] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5289.952454] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff99380b2a6300 x1872818978940032/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5295.831674] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5305.341246] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5305.914152] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5305.916515] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 5310.938718] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5311.042723] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 5311.051032] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 5316.173671] Lustre: Failing over lustre-MDT0000 [ 5318.357129] Lustre: server umount lustre-MDT0000 complete [ 5321.186101] LustreError: 149937:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5321.199491] LustreError: 149937:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 85 previous similar messages [ 5321.571717] Lustre: Failing over lustre-MDT0001 [ 5322.054596] Lustre: server umount lustre-MDT0001 complete [ 5330.917681] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5330.954746] Lustre: lustre-MDT0000: reset Object Index mappings [ 5330.960724] Lustre: Skipped 1 previous similar message [ 5331.424086] LustreError: 16421:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9939065ba300 x1872818978969472/t0(0) o250->MGC192.168.201.121@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5331.944218] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5331.955598] Lustre: Skipped 5 previous similar messages [ 5336.812304] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5342.177894] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5342.184913] Lustre: Skipped 26 previous similar messages [ 5345.957925] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5346.282981] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5346.290809] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 5350.971540] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5351.401251] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5351.425145] Lustre: Skipped 5 previous similar messages [ 5351.474038] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5351.489700] Lustre: Skipped 5 previous similar messages [ 5351.520389] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:289) [ 5351.521447] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 5361.335497] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 20:57:14 (1786064234) [ 5371.875706] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5376.515322] Lustre: server umount lustre-MDT0000 complete [ 5379.943506] LustreError: 156254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786064254 with bad export cookie 15772276523393510491 [ 5379.947344] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5379.951869] LustreError: 156254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 15 previous similar messages [ 5379.995051] LustreError: Skipped 6 previous similar messages [ 5380.295547] Lustre: server umount lustre-MDT0001 complete [ 5394.680751] Lustre: server umount lustre-OST0000 complete [ 5408.471370] Lustre: server umount lustre-OST0001 complete [ 5415.282089] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5423.288759] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5438.819513] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5443.935536] LustreError: 161832:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.121@tcp: failed processing log, type 4: rc = -110 [ 5469.535347] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5469.539031] Lustre: Skipped 13 previous similar messages [ 5475.773831] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5481.998556] Lustre: Failing over lustre-OST0000 [ 5482.147371] Lustre: server umount lustre-OST0000 complete [ 5490.029730] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5500.705285] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5516.388926] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5521.505266] LustreError: 163363:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.121@tcp: failed processing log, type 4: rc = -110 [ 5554.032821] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5561.824277] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 21:00:35 (1786064435) [ 5576.069558] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 5587.167835] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5587.791810] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5592.159745] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5600.831799] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5601.171768] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5605.768944] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5608.973784] Lustre: 166283:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5624.666280] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5629.962473] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:321) [ 5629.972797] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:257) [ 5631.405606] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5640.122784] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5647.167265] Lustre: *** cfs_fail_loc=193, val=0*** [ 5648.867596] Lustre: Failing over lustre-MDT0000 [ 5649.251861] Lustre: server umount lustre-MDT0000 complete [ 5650.404582] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5650.413302] Lustre: Skipped 34 previous similar messages [ 5657.633793] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5657.947759] Lustre: *** cfs_fail_loc=193, val=0*** [ 5657.949817] Lustre: Skipped 1 previous similar message [ 5662.868156] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5663.237906] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:353) [ 5663.238873] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5663.296097] Lustre: *** cfs_fail_loc=193, val=0*** [ 5663.303349] Lustre: Skipped 3 previous similar messages [ 5666.751797] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5666.753761] Lustre: Skipped 71 previous similar messages [ 5666.759089] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5674.048757] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5674.053884] Lustre: Skipped 3 previous similar messages [ 5682.020594] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 21:02:34 (1786064554) [ 5684.537327] Lustre: Failing over lustre-MDT0000 [ 5684.713603] Lustre: server umount lustre-MDT0000 complete [ 5688.556579] Lustre: Failing over lustre-MDT0001 [ 5688.931902] Lustre: server umount lustre-MDT0001 complete [ 5691.594398] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5698.423488] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5699.522560] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000400:0x1:0x0]/23 with flags 0x4a: rc = 0 [ 5699.541959] Lustre: 170056:0:(lod_sub_object.c:941:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't open llog [0x200000400:0x1:0x0]: rc = -115 [ 5699.555401] LustreError: 170056:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osd: get update log duration 0, retries 0, failed: rc = -115 [ 5704.641801] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5714.229830] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5714.518686] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5714.526522] LustreError: Skipped 10 previous similar messages [ 5719.699842] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5720.826917] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000401:0x1:0x0]/22 with flags 0x4a: rc = 0 [ 5721.098523] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:385) [ 5721.102613] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5721.904430] LustreError: 170779:0:(update_trans.c:1080:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5721.969329] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:289) [ 5721.970776] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 5725.096392] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5732.764788] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 21:03:25 (1786064605) [ 5736.417673] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5736.429573] Lustre: Skipped 3 previous similar messages [ 5740.511859] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5740.519665] Lustre: Skipped 3 previous similar messages [ 5742.385506] Lustre: server umount lustre-MDT0000 complete [ 5746.007905] Lustre: server umount lustre-MDT0001 complete [ 5760.063671] Lustre: server umount lustre-OST0000 complete [ 5774.216579] Lustre: server umount lustre-OST0001 complete [ 5781.775625] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5792.082690] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5798.134675] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5803.717951] Lustre: Failing over lustre-MDT0000 [ 5803.727249] LustreError: 173172:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5803.739825] LustreError: 173172:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5803.752041] LustreError: 173172:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 11, retries 0, failed: rc = -5 [ 5804.149504] Lustre: server umount lustre-MDT0000 complete [ 5811.193343] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5824.215409] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5829.660298] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5838.397551] Lustre: DEBUG MARKER: === sanity-scrub: start setup 21:05:11 (1786064711) === [ 5841.226688] LustreError: 174811:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5841.238651] LustreError: 174811:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5841.248214] LustreError: 174811:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 17, retries 0, failed: rc = -5 [ 5841.603552] Lustre: server umount lustre-MDT0000 complete [ 5883.538232] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_hostid [ 5890.858911] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 5938.417446] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing load_modules_local [ 5950.803396] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5951.113208] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5951.153047] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5951.222462] Lustre: lustre-MDT0000: new disk, initializing [ 5951.298467] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5955.859671] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5968.590208] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5968.671500] Lustre: 180172:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 5968.679477] Lustre: 180172:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 5968.698905] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5968.702808] Lustre: Skipped 1 previous similar message [ 5968.780641] Lustre: lustre-MDT0001: new disk, initializing [ 5968.924464] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5968.942267] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5973.575544] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5978.499438] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5988.222171] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5988.490111] Lustre: lustre-OST0000: new disk, initializing [ 5988.493664] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5988.501801] Lustre: 182109:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5990.226256] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5990.240731] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5990.325320] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5994.905156] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6008.441763] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6008.563592] Lustre: lustre-OST0001: new disk, initializing [ 6008.571652] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6008.581339] Lustre: 183134:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6010.453319] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6010.461795] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6010.545062] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6015.946414] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6025.791401] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6028.784989] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6033.517959] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 21:08:26 (1786064906) === [ 6035.049586] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 5682 sec ========= 21:08:28 (1786064908) [ 6036.764750] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 21:08:29 (1786064909) === [ 6039.855229] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 21:08:33 (1786064913) === [ 6045.680535] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6049.399414] Lustre: server umount lustre-MDT0000 complete [ 6051.809196] LustreError: 180182:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6051.826480] LustreError: 180182:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 70 previous similar messages [ 6058.068476] LustreError: 180163:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786064932 with bad export cookie 15772276523393537161 [ 6058.069473] LustreError: MGC192.168.201.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6058.076587] LustreError: 180163:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 6058.086361] LustreError: Skipped 3 previous similar messages [ 6058.356608] Lustre: server umount lustre-MDT0001 complete [ 6076.997783] Lustre: server umount lustre-OST0000 complete [ 6078.159112] Lustre: 16422:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786064936/real 1786064936] req@ffff99380a7f4e00 x1872818979246208/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786064952 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6078.195288] Lustre: 16422:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 36 previous similar messages [ 6085.312276] Lustre: server umount lustre-OST0001 complete [ 6104.306192] Lustre: DEBUG MARKER: oleg121-server.virtnet: executing unload_modules_local [ 6106.681502] Key type lgssc unregistered [ 6106.970950] LNet: 186547:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6106.981932] LNetError: 186547:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6106.992980] LNet: Removed LNI 192.168.201.121@tcp [ 6107.929138] Key type .llcrypt unregistered [ 6107.932824] Key type ._llcrypt unregistered