[ 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 514935830 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, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001009] APIC: Switch to symmetric I/O mode setup [ 0.003159] x2apic enabled [ 0.004013] Switched APIC routing to physical x2apic. [ 0.005024] kvm-guest: setup PV IPIs [ 0.007986] ..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.008041] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009022] pid_max: default: 32768 minimum: 301 [ 0.010199] LSM: Security Framework initializing [ 0.011098] Yama: becoming mindful. [ 0.012066] SELinux: Initializing. [ 0.013110] *** VALIDATE selinux *** [ 0.022762] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027600] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028206] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029169] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030162] *** VALIDATE tmpfs *** [ 0.031615] *** VALIDATE proc *** [ 0.032351] *** VALIDATE cgroup *** [ 0.033019] *** VALIDATE cgroup2 *** [ 0.034345] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036128] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037016] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038045] Spectre V2 : User space: Vulnerable [ 0.040005] Speculative Store Bypass: Vulnerable [ 0.043539] debug: unmapping init [mem 0xffffffffb1e59000-0xffffffffb1e60fff] [ 0.045208] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046849] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047034] ... version: 2 [ 0.048024] ... bit width: 48 [ 0.049018] ... generic registers: 4 [ 0.050018] ... value mask: 0000ffffffffffff [ 0.051023] ... max period: 00007fffffffffff [ 0.052018] ... fixed-purpose events: 3 [ 0.053018] ... event mask: 000000070000000f [ 0.055302] rcu: Hierarchical SRCU implementation. [ 0.057896] smp: Bringing up secondary CPUs ... [ 0.058745] x86: Booting SMP configuration: [ 0.059039] .... node #0, CPUs: #1 #2 #3 [ 0.063117] smp: Brought up 1 node, 4 CPUs [ 0.065021] smpboot: Max logical packages: 1 [ 0.066021] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.295810] node 0 deferred pages initialised in 228ms [ 0.299490] devtmpfs: initialized [ 0.301243] x86/mm: Memory block size: 128MB [ 0.303905] gcov: version magic: 0x41383552 [ 0.306320] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.310109] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.312370] pinctrl core: initialized pinctrl subsystem [ 0.314216] [ 0.314792] ************************************************************* [ 0.317016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.320018] ** ** [ 0.322010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.324015] ** ** [ 0.327015] ** This means that this kernel is built to expose internal ** [ 0.329013] ** IOMMU data structures, which may compromise security on ** [ 0.331020] ** your system. ** [ 0.334016] ** ** [ 0.336014] ** If you see this message and you are not debugging the ** [ 0.338012] ** kernel, report this immediately to your vendor! ** [ 0.340016] ** ** [ 0.341013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.343010] ************************************************************* [ 0.344582] NET: Registered protocol family 16 [ 0.346422] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.349068] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.351045] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.355040] cpuidle: using governor menu [ 0.357000] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.359717] PCI: Using configuration type 1 for base access [ 0.361157] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.370045] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.372025] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.375106] cryptd: max_cpu_qlen set to 1000 [ 0.378701] ACPI: Added _OSI(Module Device) [ 0.381040] ACPI: Added _OSI(Processor Device) [ 0.383025] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.385018] ACPI: Added _OSI(Processor Aggregator Device) [ 0.389151] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.397555] ACPI: Interpreter enabled [ 0.399094] ACPI: PM: (supports S0 S3 S4 S5) [ 0.400047] ACPI: Using IOAPIC for interrupt routing [ 0.402127] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.404846] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.415863] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.418047] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.420020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.422110] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.426417] acpiphp: Slot [2] registered [ 0.428135] acpiphp: Slot [5] registered [ 0.430140] acpiphp: Slot [6] registered [ 0.431194] acpiphp: Slot [7] registered [ 0.433136] acpiphp: Slot [8] registered [ 0.435451] acpiphp: Slot [9] registered [ 0.436136] acpiphp: Slot [10] registered [ 0.438137] acpiphp: Slot [3] registered [ 0.439162] acpiphp: Slot [4] registered [ 0.441115] acpiphp: Slot [11] registered [ 0.442122] acpiphp: Slot [12] registered [ 0.444126] acpiphp: Slot [13] registered [ 0.446150] acpiphp: Slot [14] registered [ 0.448114] acpiphp: Slot [15] registered [ 0.449136] acpiphp: Slot [16] registered [ 0.451155] acpiphp: Slot [17] registered [ 0.452115] acpiphp: Slot [18] registered [ 0.454104] acpiphp: Slot [19] registered [ 0.455099] acpiphp: Slot [20] registered [ 0.456098] acpiphp: Slot [21] registered [ 0.457123] acpiphp: Slot [22] registered [ 0.459166] acpiphp: Slot [23] registered [ 0.461100] acpiphp: Slot [24] registered [ 0.462110] acpiphp: Slot [25] registered [ 0.463095] acpiphp: Slot [26] registered [ 0.464115] acpiphp: Slot [27] registered [ 0.465091] acpiphp: Slot [28] registered [ 0.466112] acpiphp: Slot [29] registered [ 0.468113] acpiphp: Slot [30] registered [ 0.469113] acpiphp: Slot [31] registered [ 0.470059] PCI host bridge to bus 0000:00 [ 0.471017] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.473021] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.475021] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.477023] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.479020] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.481026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.483186] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.484984] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.488000] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.497017] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.501486] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.503018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.505019] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.507015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.509282] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.512724] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.515049] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.517792] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.523019] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.535017] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.541847] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.547425] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.554018] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.561025] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.577023] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.588607] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.596019] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.609018] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.628021] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.638734] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.652021] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.663019] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.694022] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.707277] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.715025] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.722031] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.745019] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.758757] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.764018] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.770017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.784027] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.793564] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.798018] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.803018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.817021] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.827429] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.829509] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.832382] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.835455] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.837265] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.841197] iommu: Default domain type: Passthrough [ 0.843716] SCSI subsystem initialized [ 0.845197] ACPI: bus type USB registered [ 0.847183] usbcore: registered new interface driver usbfs [ 0.849131] usbcore: registered new interface driver hub [ 0.851134] usbcore: registered new device driver usb [ 0.853244] pps_core: LinuxPPS API ver. 1 registered [ 0.855017] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.858113] PTP clock support registered [ 0.860240] EDAC MC: Ver: 3.0.0 [ 0.863078] PCI: Using ACPI for IRQ routing [ 0.865133] NetLabel: Initializing [ 0.866016] NetLabel: domain hash size = 128 [ 0.868014] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.870103] NetLabel: unlabeled traffic allowed by default [ 0.872224] vgaarb: loaded [ 0.873355] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.875019] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.879006] clocksource: Switched to clocksource kvm-clock [ 0.991227] VFS: Disk quotas dquot_6.6.0 [ 0.992441] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.994403] *** VALIDATE ramfs *** [ 0.995388] *** VALIDATE hugetlbfs *** [ 0.996766] pnp: PnP ACPI init [ 0.998710] pnp: PnP ACPI: found 6 devices [ 1.017329] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.021124] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.023791] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.026187] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.028636] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.031101] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.034127] NET: Registered protocol family 2 [ 1.036678] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.041524] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.044681] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.050084] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.053833] TCP: Hash tables configured (established 65536 bind 65536) [ 1.056767] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.059947] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.062401] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.064930] NET: Registered protocol family 1 [ 1.067430] RPC: Registered named UNIX socket transport module. [ 1.069016] RPC: Registered udp transport module. [ 1.070266] RPC: Registered tcp transport module. [ 1.071625] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.074501] NET: Registered protocol family 44 [ 1.075613] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.077095] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.078913] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.081078] PCI: CLS 0 bytes, default 64 [ 1.082395] Unpacking initramfs... [ 2.460143] debug: unmapping init [mem 0xffff92eafcc54000-0xffff92eafffbffff] [ 2.466840] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.469416] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.474265] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.969154] Initialise system trusted keyrings [ 2.972219] Key type blacklist registered [ 2.974754] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.985965] zbud: loaded [ 2.989837] *** VALIDATE nfs *** [ 2.991202] *** VALIDATE nfs4 *** [ 2.992933] pstore: using deflate compression [ 2.997879] Platform Keyring initialized [ 3.103573] NET: Registered protocol family 38 [ 3.105268] Key type asymmetric registered [ 3.106797] Asymmetric key parser 'x509' registered [ 3.108697] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.112364] io scheduler mq-deadline registered [ 3.114141] io scheduler kyber registered [ 3.115900] io scheduler bfq registered [ 3.117625] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.120259] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.123308] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.126179] ACPI: Power Button [PWRF] [ 3.131809] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.138717] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.152035] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.164229] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.183312] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.212291] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.240486] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.247278] Non-volatile memory driver v1.3 [ 3.248874] Linux agpgart interface v0.103 [ 3.282750] virtio_blk virtio1: [vda] 149376 512-byte logical blocks (76.5 MB/72.9 MiB) [ 3.285101] vda: detected capacity change from 0 to 76480512 [ 3.303057] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.305738] vdb: detected capacity change from 0 to 1073741824 [ 3.320761] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.323546] vdc: detected capacity change from 0 to 2621440000 [ 3.337416] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.340684] vdd: detected capacity change from 0 to 2621440000 [ 3.354718] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.357658] vde: detected capacity change from 0 to 4294967296 [ 3.371406] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.374183] vdf: detected capacity change from 0 to 4294967296 [ 3.383651] libphy: Fixed MDIO Bus: probed [ 3.400388] usbcore: registered new interface driver usbserial_generic [ 3.403119] usbserial: USB Serial support registered for generic [ 3.405956] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.410937] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.412955] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.415940] mousedev: PS/2 mouse device common for all mice [ 3.420615] rtc_cmos 00:05: RTC can wake from S4 [ 3.425393] rtc_cmos 00:05: registered as rtc0 [ 3.427156] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.430474] intel_pstate: CPU model not supported [ 3.432907] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.435013] hid: raw HID events driver (C) Jiri Kosina [ 3.442067] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.442993] usbcore: registered new interface driver usbhid [ 3.447934] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.448656] usbhid: USB HID core driver [ 3.448822] drop_monitor: Initializing network drop monitor service [ 3.455530] Initializing XFRM netlink socket [ 3.457566] NET: Registered protocol family 10 [ 3.460472] Segment Routing with IPv6 [ 3.461665] NET: Registered protocol family 17 [ 3.463474] mpls_gso: MPLS GSO support [ 3.468413] RAS: Correctable Errors collector initialized. [ 3.470147] AVX version of gcm_enc/dec engaged. [ 3.471569] AES CTR mode by8 optimization enabled [ 3.528033] sched_clock: Marking stable (3528008412, 0)->(4340001403, -811992991) [ 3.531262] registered taskstats version 1 [ 3.533090] Loading compiled-in X.509 certificates [ 3.534947] zswap: loaded using pool lzo/zbud [ 3.561099] Key type big_key registered [ 3.573094] Key type encrypted registered [ 3.575259] ima: No TPM chip found, activating TPM-bypass! [ 3.578208] ima: Allocated hash algorithm: sha1 [ 3.580656] ima: No architecture policies found [ 3.583136] evm: Initialising EVM extended attributes: [ 3.585857] evm: security.selinux [ 3.587438] evm: security.ima [ 3.588790] evm: security.capability [ 3.590413] evm: HMAC attrs: 0x1 [ 3.593909] rtc_cmos 00:05: setting system clock to 2026-08-22 10:14:29 UTC (1787393669) [ 3.600167] debug: unmapping init [mem 0xffffffffb2e03000-0xffffffffb2ffffff] [ 3.604479] debug: unmapping init [mem 0xffffffffb1b82000-0xffffffffb1e58fff] [ 3.613080] Write protecting the kernel read-only data: 28672k [ 3.616917] debug: unmapping init [mem 0xffffffffb0203000-0xffffffffb03fffff] [ 3.619560] debug: unmapping init [mem 0xffffffffb0b14000-0xffffffffb0bfffff] [ 3.657178] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.662813] systemd[1]: Detected virtualization kvm. [ 3.664648] systemd[1]: Detected architecture x86-64. [ 3.666872] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.693170] systemd[1]: No hostname configured. [ 3.694466] systemd[1]: Set hostname to . [ 3.695866] random: systemd: uninitialized urandom read (16 bytes read) [ 3.698033] systemd[1]: Initializing machine ID from random generator. [ 3.828090] random: systemd: uninitialized urandom read (16 bytes read) [ 3.831093] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ 3.835289] random: systemd: uninitialized urandom read (16 bytes read) [ 3.838559] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.843537] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Swap. [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Create Volatile Files and Directories... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... Starting Apply Kernel Variables... [ OK ] Reached target Initrd Root Device. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.411854] device-mapper: uevent: version 1.0.3 [ 4.414189] 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... [ 4.995615] random: fast init done [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.036962] virtio_net virtio0 ens2: renamed from eth0 [ 5.127766] scsi host0: ata_piix [ 5.133717] scsi host1: ata_piix [ 5.135398] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.137924] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.740855] dracut-initqueue[580]: RTNETLINK answers: File exists [ 10.096303] random: crng init done [ 10.097567] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.430690] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.578460] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.838477] SELinux: Disabled at runtime. [ 11.899187] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 11.908158] systemd[1]: Detected virtualization kvm. [ 11.910083] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.416437] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.419445] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.424478] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.429227] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.433238] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.439950] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.444431] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Created slice User and Session Slice. Mounting Kernel Debug File System... Starting Create list of required st…ce nodes for the current kernel... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on Process Core Dump Socket. [ 12.501989] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Control Socket. Starting Apply Kernel Variables... [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting POSIX Message Queue File System... Mounting Huge Pages File System... [ OK ] Created slice system-getty.slice. [ OK ] Reached target Slices. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Flush Journal to Persistent Storage. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 12.810594] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ OK ] Started udev Coldplug all Devices. [ 13.107105] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.205600] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.282958] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.291748] EDAC sbridge: Ver: 1.1.2 [ 14.964697] Key type dns_resolver registered [ 15.278908] NFS: Registering the id_resolver key type [ 15.280367] Key type id_resolver registered [ 15.281685] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started 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. [ OK ] Reached target sshd-keygen.target. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ 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 ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg211-server login: [ 50.424105] libcfs: loading out-of-tree module taints kernel. [ 50.524752] Key type ._llcrypt registered [ 50.527184] Key type .llcrypt registered [ 50.627652] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_hostid [ 70.264516] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 71.752065] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 71.765864] alg: No test for adler32 (adler32-zlib) [ 73.133632] Lustre: Lustre: Build Version: 2.17.54_107_g42be189 [ 74.008940] LNet: Added LNI 192.168.202.111@tcp [8/256/0/180] [ 75.823175] Key type lgssc registered [ 77.785521] Lustre: Echo OBD driver; http://www.lustre.org/ [ 91.123964] hrtimer: interrupt took 7953607 ns [ 95.649286] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 146.780329] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 164.100530] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 164.155961] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 165.545172] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 165.588364] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 165.725433] Lustre: lustre-MDT0000: new disk, initializing [ 165.852602] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 165.869236] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 170.935450] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 184.283418] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 184.425871] Lustre: 6529: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 [ 184.442534] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 184.445225] Lustre: Skipped 1 previous similar message [ 184.517871] Lustre: lustre-MDT0001: new disk, initializing [ 184.579060] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 184.619283] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 184.625769] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 189.584842] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 194.522805] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 203.538685] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 203.867500] Lustre: lustre-OST0000: new disk, initializing [ 203.881236] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 203.896774] Lustre: 8468:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 203.970749] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 209.438596] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 209.447541] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 209.541718] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 210.663649] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 225.674744] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 225.815489] Lustre: lustre-OST0001: new disk, initializing [ 225.819645] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 225.830673] Lustre: 9543:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 225.900269] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 230.932512] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 230.953709] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 231.085996] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 232.918842] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 245.439658] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 252.636341] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 259.212275] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing check_logdir /tmp/testlogs/ [ 264.016636] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing yml_node [ 269.228416] Lustre: DEBUG MARKER: Client: 2.17.54.107 [ 271.739569] Lustre: DEBUG MARKER: MDS: 2.17.54.107 [ 274.602402] Lustre: DEBUG MARKER: OSS: 2.17.54.107 [ 276.697738] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Sat Aug 22 06:19:01 EDT 2026 [ 294.967468] Lustre: DEBUG MARKER: excepting tests: [ 306.735418] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 317.919783] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 317.922771] 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 [ 317.923567] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 317.948448] Lustre: Skipped 3 previous similar messages [ 320.577533] Lustre: server umount lustre-MDT0000 complete [ 328.160638] LustreError: 6542:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 328.179672] LustreError: 6542:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 329.291606] LustreError: 6524:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787393995 with bad export cookie 5786022540554545859 [ 329.298945] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 329.301033] LustreError: 6524:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 329.818528] Lustre: server umount lustre-MDT0001 complete [ 348.320545] Lustre: server umount lustre-OST0000 complete [ 349.667963] Lustre: 3641:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787393999/real 1787393999] req@ffff92ea4317d500 x1874218177369088/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394015 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 349.701556] 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 [ 350.175117] Lustre: 3643:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394000/real 1787394000] req@ffff92ea4317d880 x1874218177369344/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394016 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 354.784150] Lustre: 3642:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394004/real 1787394004] req@ffff92eb6f31df80 x1874218177369600/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394020 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 357.889343] Lustre: server umount lustre-OST0001 complete [ 377.437960] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing unload_modules_local [ 381.467641] Key type lgssc unregistered [ 381.707482] LNet: 14816:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 381.713880] LNetError: 14816:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 381.734174] LNet: Removed LNI 192.168.202.111@tcp [ 382.576297] Key type .llcrypt unregistered [ 382.579756] Key type ._llcrypt unregistered [ 406.547696] Key type ._llcrypt registered [ 406.557096] Key type .llcrypt registered [ 406.714308] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_hostid [ 421.050947] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 422.483525] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 422.631606] alg: No test for adler32 (adler32-zlib) [ 423.752794] Lustre: Lustre: Build Version: 2.17.54_107_g42be189 [ 424.012864] LNet: Added LNI 192.168.202.111@tcp [8/256/0/180] [ 425.679172] Key type lgssc registered [ 427.108684] Lustre: Echo OBD driver; http://www.lustre.org/ [ 482.329920] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 494.707934] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 494.728281] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 496.047762] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 496.068500] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 496.143960] Lustre: lustre-MDT0000: new disk, initializing [ 496.212395] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 496.229098] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 500.764935] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 515.914803] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 516.029121] Lustre: 19271: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 [ 516.069113] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 516.072719] Lustre: Skipped 1 previous similar message [ 516.154833] Lustre: lustre-MDT0001: new disk, initializing [ 516.231979] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 516.260029] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 516.280602] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 521.199807] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 526.981850] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 536.877620] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 537.096707] Lustre: lustre-OST0000: new disk, initializing [ 537.100892] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 537.106287] Lustre: 21210:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 537.164829] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 542.291571] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 543.253101] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 543.266846] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 543.432468] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 557.004280] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 557.122217] Lustre: lustre-OST0001: new disk, initializing [ 557.124846] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 557.130163] Lustre: 22234:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 557.193609] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 565.346149] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 565.364173] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 565.459842] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 565.493508] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 577.927233] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 590.162786] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 599.213245] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 06:24:23 (1787394263) === [ 601.355876] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 06:24:25 (1787394265) [ 627.377831] Lustre: Failing over lustre-MDT0000 [ 627.826076] Lustre: server umount lustre-MDT0000 complete [ 629.216179] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 629.227260] 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 [ 632.292129] 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 [ 632.327565] Lustre: Skipped 2 previous similar messages [ 632.338621] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394298 with bad export cookie 4603077130831798127 [ 632.339571] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 632.339811] Lustre: Failing over lustre-MDT0001 [ 632.354618] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 632.766263] Lustre: server umount lustre-MDT0001 complete [ 642.418462] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 642.903295] LustreError: 21202:0:(ldlm_lib.c:1179: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. [ 642.942988] LustreError: 21202:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 643.053831] 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 [ 643.120839] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 643.174536] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 648.164881] LustreError: 24252:0:(ldlm_lib.c:1179: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. [ 648.192648] LustreError: 24252:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 648.461266] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 652.277768] LustreError: 24251:0:(ldlm_lib.c:1179: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. [ 652.301132] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 652.308076] LustreError: 24251:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 653.281075] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394303/real 1787394303] req@ffff92ea44eb5c00 x1874218544404608/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394319 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 657.378754] LustreError: 24251:0:(ldlm_lib.c:1179: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. [ 657.407652] LustreError: 24251:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 658.337556] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 658.399108] Lustre: 16431:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394308/real 1787394308] req@ffff92ea439c1f80 x1874218544404864/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394324 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 658.434300] Lustre: 16431:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 658.850707] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 658.936642] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 659.011305] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 659.026661] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 664.051779] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 664.053553] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 664.069404] Lustre: Skipped 1 previous similar message [ 664.113889] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 664.218056] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 664.219738] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 664.895740] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 682.068503] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 06:25:46 (1787394346) [ 706.891092] Lustre: Failing over lustre-MDT0000 [ 707.325169] Lustre: server umount lustre-MDT0000 complete [ 710.114880] 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 [ 710.124138] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 710.124362] LustreError: 24250:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 710.139154] Lustre: Skipped 3 previous similar messages [ 711.190544] Lustre: Failing over lustre-MDT0001 [ 711.191865] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394377 with bad export cookie 4603077130831814451 [ 711.204972] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 711.245036] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 711.651544] Lustre: server umount lustre-MDT0001 complete [ 721.969959] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 731.615335] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394381/real 1787394381] req@ffff92ea4324fb80 x1874218544533632/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394397 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 731.655419] 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 [ 731.680105] Lustre: Skipped 1 previous similar message [ 736.800293] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394386/real 1787394386] req@ffff92ea44c50700 x1874218544534144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394402 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 736.834990] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 737.130160] LustreError: 25762:0:(ldlm_lib.c:1179: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. [ 737.150966] LustreError: 25762:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 737.234340] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 737.272578] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 742.393420] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 742.437922] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394392/real 1787394392] req@ffff92ea44eb5c00 x1874218544534784/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394408 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 742.483111] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 750.583703] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 750.586768] Lustre: Skipped 2 previous similar messages [ 752.445462] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 752.631738] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 752.816818] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 752.826332] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 757.736718] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 758.242510] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 758.246836] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 758.263966] Lustre: Skipped 1 previous similar message [ 758.299098] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 758.339790] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 758.339800] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 762.508367] Lustre: *** cfs_fail_loc=193, val=0*** [ 767.284906] Lustre: Failing over lustre-MDT0000 [ 767.580796] Lustre: server umount lustre-MDT0000 complete [ 768.479693] 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 [ 768.480614] LustreError: 26651:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 768.497905] Lustre: Skipped 3 previous similar messages [ 768.500859] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 768.513262] LustreError: 26651:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 775.722943] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 775.794746] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 776.050805] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 776.055338] Lustre: Skipped 1 previous similar message [ 776.105407] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 780.314979] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 781.294032] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 781.298653] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 781.318802] Lustre: Skipped 2 previous similar messages [ 781.353670] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 781.421046] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 781.421277] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 789.180592] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 06:27:34 (1787394454) [ 803.946397] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 823.801586] Lustre: 30528:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 849.023763] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 852.645433] Lustre: 31664:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 866.650192] Lustre: *** cfs_fail_loc=198, val=0*** [ 879.001946] Lustre: Failing over lustre-MDT0000 [ 879.284857] Lustre: server umount lustre-MDT0000 complete [ 882.695111] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394548 with bad export cookie 4603077130831843851 [ 882.702387] Lustre: Failing over lustre-MDT0001 [ 882.703289] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 882.713813] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 883.067374] Lustre: server umount lustre-MDT0001 complete [ 887.081749] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 891.356897] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 899.564111] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 900.063166] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394549/real 1787394549] req@ffff92eb6e04fb80 x1874218544702336/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394565 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 900.064553] 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 [ 900.094656] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 900.113511] Lustre: Skipped 4 previous similar messages [ 907.298371] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92ea43b9f100 x1874218544705152/t0(0) o250->MGC192.168.202.111@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 [ 907.637769] LustreError: 25762:0:(ldlm_lib.c:1179: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. [ 907.646591] LustreError: 25762:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 907.755802] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 907.796313] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 910.834822] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 910.852141] Lustre: Skipped 3 previous similar messages [ 914.151685] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 922.397083] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 922.694047] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 922.906918] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 922.908158] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 926.999848] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 928.226760] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 928.234149] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 928.242058] Lustre: Skipped 1 previous similar message [ 928.283713] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 928.334878] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 928.335295] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 940.263289] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 06:30:04 (1787394604) [ 964.079933] Lustre: Failing over lustre-MDT0000 [ 964.371576] Lustre: server umount lustre-MDT0000 complete [ 968.224457] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394634 with bad export cookie 4603077130831870794 [ 968.234964] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 968.235814] Lustre: Failing over lustre-MDT0001 [ 968.443778] Lustre: server umount lustre-MDT0001 complete [ 973.406765] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 977.411559] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 985.375116] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394635/real 1787394635] req@ffff92eb6e196680 x1874218544822912/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394651 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 985.376982] 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 [ 985.441122] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 985.480751] Lustre: Skipped 1 previous similar message [ 987.320148] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 987.439790] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 993.700970] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328f5a761 [ 993.705611] Lustre: MGC192.168.202.111@tcp: Connection restored to 0@lo (at 0@lo) [ 993.708268] Lustre: Skipped 2 previous similar messages [ 993.943551] LustreError: 21202:0:(ldlm_lib.c:1179: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. [ 993.978960] LustreError: 21202:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 994.129879] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 998.627686] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1006.944643] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1007.002394] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1007.380373] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1007.509772] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:233 to 0x2c0000400:257) [ 1007.513540] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 1012.266360] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1012.717083] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1012.766702] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1012.814180] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1012.816978] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 1038.083264] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 1063.032057] Lustre: 38962:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1087.278872] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1091.632524] Lustre: 40098:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1118.040651] Lustre: Failing over lustre-MDT0000 [ 1118.439849] Lustre: server umount lustre-MDT0000 complete [ 1120.224088] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1120.230929] 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 [ 1120.239615] Lustre: Skipped 5 previous similar messages [ 1124.228520] Lustre: Failing over lustre-MDT0001 [ 1124.230561] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394790 with bad export cookie 4603077130831898465 [ 1124.233691] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1124.267313] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 1124.700354] Lustre: server umount lustre-MDT0001 complete [ 1129.667640] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1139.345094] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1141.734857] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394791/real 1787394791] req@ffff92ea44ed3100 x1874218544970880/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394807 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1141.775214] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 17 previous similar messages [ 1152.981797] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1153.017389] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1169.440935] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328f61179 [ 1169.457321] Lustre: MGC192.168.202.111@tcp: Connection restored to 0@lo (at 0@lo) [ 1169.472860] Lustre: Skipped 5 previous similar messages [ 1169.873696] LustreError: 21203:0:(ldlm_lib.c:1179: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. [ 1169.890880] LustreError: 21203:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 17 previous similar messages [ 1170.014604] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1170.026926] Lustre: Skipped 3 previous similar messages [ 1170.087937] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1174.884616] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1183.889419] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1183.942143] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1184.241772] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1184.399927] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1184.400520] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1185.385358] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1185.443954] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1185.499298] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1185.501306] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 1188.676163] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1214.007859] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 1233.507343] Lustre: 44810:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1259.348257] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1263.122795] Lustre: 45947:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1285.886645] Lustre: Failing over lustre-MDT0000 [ 1286.320618] Lustre: server umount lustre-MDT0000 complete [ 1288.163813] 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 [ 1288.212550] Lustre: Skipped 2 previous similar messages [ 1290.606754] Lustre: Failing over lustre-MDT0001 [ 1290.607746] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787394956 with bad export cookie 4603077130831925625 [ 1290.612023] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1290.654989] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1291.217458] Lustre: server umount lustre-MDT0001 complete [ 1296.133693] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1304.017115] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1310.687149] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787394960/real 1787394960] req@ffff92eb44a6f100 x1874218545120512/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787394976 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1310.710337] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1314.868440] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1314.987929] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1315.883229] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328f67b91 [ 1315.913210] Lustre: MGC192.168.202.111@tcp: Connection restored to 0@lo (at 0@lo) [ 1315.938993] Lustre: Skipped 5 previous similar messages [ 1316.509809] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1321.537494] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1331.381531] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1331.438273] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1331.693504] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1331.708273] LustreError: Skipped 1 previous similar message [ 1331.951777] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:361 to 0x2c0000400:385) [ 1331.958254] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1336.756513] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1337.322414] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1337.401781] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1337.465502] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 1337.467023] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1354.642748] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 06:36:59 (1787395019) [ 1369.041757] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 1391.834183] Lustre: 50660:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1421.089895] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1450.261001] Lustre: Failing over lustre-MDT0000 [ 1450.861338] Lustre: server umount lustre-MDT0000 complete [ 1454.854259] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787395120 with bad export cookie 4603077130831952785 [ 1454.861786] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1454.862938] Lustre: Failing over lustre-MDT0001 [ 1454.870951] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1455.082300] LustreError: 47517:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1455.098522] LustreError: 47517:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 21 previous similar messages [ 1455.187429] Lustre: server umount lustre-MDT0001 complete [ 1461.433908] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1473.288601] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1482.624988] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1493.169849] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1505.769940] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1505.787582] Lustre: lustre-MDT0000: reset Object Index mappings [ 1524.707965] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328f6e5a9 [ 1525.363615] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1525.369173] Lustre: Skipped 3 previous similar messages [ 1525.403838] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1531.868838] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1543.079366] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1543.132857] Lustre: lustre-MDT0001: reset Object Index mappings [ 1543.835593] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1543.841096] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 1544.803904] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1544.888609] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1545.007877] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 1545.008076] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1550.486140] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1564.251365] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 06:40:28 (1787395228) [ 1588.946358] Lustre: Failing over lustre-MDT0000 [ 1589.228700] Lustre: server umount lustre-MDT0000 complete [ 1591.267701] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1591.270755] 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 [ 1591.287544] LustreError: Skipped 1 previous similar message [ 1591.312793] Lustre: Skipped 10 previous similar messages [ 1594.471121] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787395260 with bad export cookie 4603077130831979945 [ 1594.472441] Lustre: Failing over lustre-MDT0001 [ 1594.486954] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1594.489470] LustreError: 19264:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1595.285334] Lustre: server umount lustre-MDT0001 complete [ 1601.422724] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1612.772101] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787395262/real 1787395262] req@ffff92eb6e174380 x1874218545393280/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787395278 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1612.821806] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1612.877285] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1623.676881] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1633.467986] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1649.108193] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1649.138289] Lustre: lustre-MDT0000: reset Object Index mappings [ 1664.497969] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1669.288701] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1678.770902] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1678.788216] Lustre: lustre-MDT0001: reset Object Index mappings [ 1679.298111] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:489 to 0x280000400:513) [ 1679.310616] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1681.313427] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1681.329604] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1681.340617] Lustre: Skipped 11 previous similar messages [ 1681.397844] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1681.463689] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1681.462630] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:521 to 0x2c0000401:545) [ 1684.438200] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1691.423037] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32041: rc = 0 [ 1692.600502] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/38 with flags 0x52: rc = 0 [ 1716.152039] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 06:43:00 (1787395380) [ 1740.835534] Lustre: Failing over lustre-MDT0000 [ 1741.135738] Lustre: server umount lustre-MDT0000 complete [ 1745.466470] LustreError: 19263:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787395411 with bad export cookie 4603077130832007483 [ 1745.484861] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1745.491656] Lustre: Failing over lustre-MDT0001 [ 1745.713384] Lustre: server umount lustre-MDT0001 complete [ 1751.800204] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1764.407759] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1772.685398] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1782.275210] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1795.059680] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1795.086614] Lustre: lustre-MDT0000: reset Object Index mappings [ 1816.026965] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1821.633529] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1832.065422] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1832.084995] Lustre: lustre-MDT0001: reset Object Index mappings [ 1832.539660] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1832.541654] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1833.512073] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1833.588444] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1833.662762] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:585 to 0x280000401:609) [ 1833.663943] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1837.536478] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1846.458740] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32027: rc = 0 [ 1849.836156] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32007 with flags 0x52: rc = 0 [ 1967.776304] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 06:47:12 (1787395632) [ 2000.064088] Lustre: Failing over lustre-MDT0000 [ 2000.433265] Lustre: server umount lustre-MDT0000 complete [ 2002.915505] LustreError: 25762:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2002.935995] LustreError: 25762:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 20 previous similar messages [ 2004.410279] LustreError: 19262:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787395670 with bad export cookie 4603077130832035154 [ 2004.417278] Lustre: Failing over lustre-MDT0001 [ 2004.425315] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2004.444782] LustreError: 19262:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2005.113484] Lustre: server umount lustre-MDT0001 complete [ 2010.414473] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2020.658330] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2024.423862] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787395674/real 1787395674] req@ffff92eb763cfb80 x1874218545718912/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787395690 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2024.449275] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 2031.216593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2041.954072] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2053.374892] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2053.398114] Lustre: lustre-MDT0000: reset Object Index mappings [ 2074.723492] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb763cd880 x1874218545722368/t0(0) o250->MGC192.168.202.111@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 [ 2075.148832] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2075.152927] Lustre: Skipped 5 previous similar messages [ 2075.187946] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2079.110312] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2088.389472] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2088.426287] Lustre: lustre-MDT0001: reset Object Index mappings [ 2088.893847] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 2088.896269] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:617 to 0x2c0000400:641) [ 2093.965339] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2093.993564] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2094.025600] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2094.082407] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:649 to 0x2c0000401:673) [ 2094.082790] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2102.447194] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/64002: rc = 0 [ 2105.826893] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32006 with flags 0x52: rc = 0 [ 2196.407935] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 06:51:01 (1787395861) [ 2211.545714] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2211.555851] Lustre: Skipped 1 previous similar message [ 2212.058303] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2212.060762] Lustre: Skipped 39 previous similar messages [ 2213.066224] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2213.069331] Lustre: Skipped 203 previous similar messages [ 2231.272422] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 06:51:36 (1787395896) [ 2236.173214] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2236.178764] Lustre: Skipped 211 previous similar messages [ 2236.630594] LustreError: 34651:0:(osd_compat.c:736:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 264/1555137166 265/132328831 [ 2252.067835] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 06:51:56 (1787395916) [ 2269.152497] 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 [ 2269.155176] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2269.167196] Lustre: Skipped 17 previous similar messages [ 2269.183440] Lustre: Skipped 3 previous similar messages [ 2274.274855] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2274.629905] Lustre: server umount lustre-MDT0000 complete [ 2278.875867] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787395944 with bad export cookie 4603077130832079310 [ 2278.886020] LustreError: 21209:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2279.399774] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2279.405351] Lustre: Skipped 4 previous similar messages [ 2283.431229] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2283.438235] Lustre: Skipped 1 previous similar message [ 2288.547372] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2293.217539] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2293.662913] Lustre: server umount lustre-MDT0001 complete [ 2298.082546] LustreError: 72703:0:(ldlm_resource.c:1207:ldlm_resource_complain()) filter-lustre-OST0000_UUID: namespace resource [0x280000401:0x30b:0x0].0x0 (ffff92eb6f104300) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 2304.339730] Lustre: server umount lustre-OST0000 complete [ 2315.120954] Lustre: server umount lustre-OST0001 complete [ 2323.006158] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_hostid [ 2334.071855] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 2386.381778] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 2398.652194] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2399.034882] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2399.060994] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2399.205492] Lustre: lustre-MDT0000: new disk, initializing [ 2399.432505] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2405.499571] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2417.502425] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2417.715682] Lustre: 75830: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 [ 2417.731583] Lustre: 75830:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2417.772177] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2417.777293] Lustre: Skipped 1 previous similar message [ 2417.859799] Lustre: lustre-MDT0001: new disk, initializing [ 2418.037685] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2418.061150] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2423.862166] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2430.416725] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2438.721986] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2439.225938] Lustre: lustre-OST0000: new disk, initializing [ 2439.232861] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2439.249314] Lustre: 77461:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2440.364383] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2440.371361] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2440.473579] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2446.158522] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2457.868222] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2458.019237] Lustre: lustre-OST0001: new disk, initializing [ 2458.024785] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2458.030809] Lustre: 78331:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2460.141855] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2460.159589] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2460.293151] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2465.783920] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2477.092938] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2481.071964] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2503.477880] Lustre: Failing over lustre-MDT0000 [ 2503.947479] Lustre: server umount lustre-MDT0000 complete [ 2505.186758] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2505.200356] LustreError: Skipped 5 previous similar messages [ 2508.218944] Lustre: Failing over lustre-MDT0001 [ 2508.527468] Lustre: server umount lustre-MDT0001 complete [ 2515.325715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2526.274291] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2534.590782] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2539.999227] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787396189/real 1787396189] req@ffff92ea41ebf800 x1874218546047872/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787396205 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2540.023692] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 17 previous similar messages [ 2545.950306] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2559.141856] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2559.160101] Lustre: lustre-MDT0000: reset Object Index mappings [ 2578.920251] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb81594700 x1874218546050560/t0(0) o250->MGC192.168.202.111@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 [ 2584.335378] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2593.525923] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2594.157396] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2594.160357] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 2596.131835] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2596.140355] Lustre: Skipped 14 previous similar messages [ 2596.215132] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 2596.215583] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2599.354954] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2611.990737] Lustre: *** cfs_fail_loc=190, val=3*** [ 2611.991095] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32042: rc = 0 [ 2613.051892] Lustre: *** cfs_fail_loc=190, val=3*** [ 2613.054578] Lustre: Skipped 1 previous similar message [ 2614.132617] Lustre: *** cfs_fail_loc=190, val=3*** [ 2615.306155] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 2617.183557] Lustre: *** cfs_fail_loc=190, val=3*** [ 2617.196756] Lustre: Skipped 2 previous similar messages [ 2621.472160] Lustre: *** cfs_fail_loc=190, val=3*** [ 2621.477268] Lustre: Skipped 2 previous similar messages [ 2631.280855] Lustre: Failing over lustre-MDT0000 [ 2631.507396] Lustre: server umount lustre-MDT0000 complete [ 2632.161300] LustreError: 77455:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2632.177746] LustreError: 77455:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 21 previous similar messages [ 2636.387473] Lustre: Failing over lustre-MDT0001 [ 2636.393219] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2636.426360] LustreError: Skipped 2 previous similar messages [ 2637.104711] Lustre: server umount lustre-MDT0001 complete [ 2648.258809] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2662.499842] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2662.515356] Lustre: Skipped 1 previous similar message [ 2667.006340] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2676.608194] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2677.010102] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2677.025925] Lustre: Skipped 1 previous similar message [ 2677.057898] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2677.072404] Lustre: Skipped 8 previous similar messages [ 2677.142218] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2677.153080] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:97) [ 2681.861731] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2682.363667] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 2682.369379] Lustre: Skipped 1 previous similar message [ 2682.403139] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2682.403570] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 2687.288760] Lustre: Failing over lustre-MDT0000 [ 2687.507043] Lustre: server umount lustre-MDT0000 complete [ 2691.448793] Lustre: Failing over lustre-MDT0001 [ 2691.805802] Lustre: server umount lustre-MDT0001 complete [ 2700.273347] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2700.345135] Lustre: *** cfs_fail_loc=190, val=3*** [ 2700.346887] Lustre: Skipped 3 previous similar messages [ 2701.407270] LustreError: 86115:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 2701.431605] LustreError: 86115:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff92eb46734700 x1874218546118400/t0(0) o250->MGC192.168.202.111@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1787396367 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_03.0' uid:0 gid:0 projid:4294967295 [ 2701.455078] LustreError: 86115:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 2701.730566] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328fa3122 [ 2706.827431] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2717.318193] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2717.448048] Lustre: *** cfs_fail_loc=190, val=3*** [ 2717.451956] Lustre: Skipped 5 previous similar messages [ 2717.740659] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:129) [ 2717.755579] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2722.902846] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2722.905661] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:129) [ 2725.155576] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2738.124190] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 2738.148515] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/324: rc = 0 [ 2753.321798] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 07:00:17 (1787396417) [ 2779.687875] Lustre: Failing over lustre-MDT0000 [ 2780.240525] Lustre: server umount lustre-MDT0000 complete [ 2785.204230] Lustre: Failing over lustre-MDT0001 [ 2785.790629] Lustre: server umount lustre-MDT0001 complete [ 2793.536717] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2807.123144] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2818.118990] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2830.237156] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2843.876229] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2843.894214] Lustre: lustre-MDT0000: reset Object Index mappings [ 2843.897565] Lustre: Skipped 1 previous similar message [ 2862.066636] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2872.942874] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2873.534121] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2873.535887] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2874.676837] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2874.677352] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 2879.237359] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2889.199335] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32028: rc = 0 [ 2889.204226] Lustre: *** cfs_fail_loc=190, val=2*** [ 2889.215073] Lustre: Skipped 11 previous similar messages [ 2892.584413] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/128013 with flags 0x52: rc = 0 [ 2905.663053] Lustre: lustre-MDT0001: trigger partial OI scrub for RPC inconsistency, checking FID [0x240001b71:0x44:0x0]/196: rc = 0 [ 2905.681958] Lustre: Skipped 1 previous similar message [ 2922.842296] Lustre: Failing over lustre-MDT0000 [ 2923.261823] Lustre: server umount lustre-MDT0000 complete [ 2925.033532] 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 [ 2925.052278] Lustre: Skipped 30 previous similar messages [ 2927.493496] Lustre: Failing over lustre-MDT0001 [ 2927.495864] LustreError: 83168:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787396593 with bad export cookie 4603077130832237594 [ 2927.495879] LustreError: 83168:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 12 previous similar messages [ 2928.075703] Lustre: server umount lustre-MDT0001 complete [ 2941.136569] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2953.313178] Lustre: *** cfs_fail_loc=190, val=3*** [ 2953.328348] Lustre: Skipped 30 previous similar messages [ 2959.732635] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2971.496725] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2972.030700] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2972.031194] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2977.352530] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 2977.354543] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:225) [ 2977.796922] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2998.481217] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 07:04:23 (1787396663) [ 3016.212808] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 3039.059879] Lustre: 96513:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3067.009553] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3072.035498] Lustre: 97650:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3115.449681] Lustre: Failing over lustre-MDT0000 [ 3115.496861] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3115.499215] LustreError: Skipped 8 previous similar messages [ 3115.508469] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3115.527347] Lustre: Skipped 2 previous similar messages [ 3115.723549] Lustre: server umount lustre-MDT0000 complete [ 3120.012232] Lustre: Failing over lustre-MDT0001 [ 3120.513855] Lustre: server umount lustre-MDT0001 complete [ 3126.203614] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3139.764107] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3141.857350] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787396791/real 1787396791] req@ffff92eb815af100 x1874218546463232/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787396807 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3141.914956] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 48 previous similar messages [ 3150.265418] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3162.476320] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3174.388570] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3174.422053] Lustre: lustre-MDT0000: reset Object Index mappings [ 3174.424738] Lustre: Skipped 1 previous similar message [ 3194.830990] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3204.740500] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3205.126953] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 3205.163258] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3206.124741] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3206.131713] Lustre: Skipped 25 previous similar messages [ 3206.258102] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 3206.273349] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3209.661282] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3219.175768] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/96025: rc = 0 [ 3219.179046] Lustre: *** cfs_fail_loc=190, val=3*** [ 3219.192087] Lustre: Skipped 15 previous similar messages [ 3222.460682] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32007 with flags 0x52: rc = 0 [ 3247.711720] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 07:08:32 (1787396912) [ 3298.070936] Lustre: Failing over lustre-MDT0000 [ 3298.279311] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3298.285397] Lustre: Skipped 2 previous similar messages [ 3300.382606] Lustre: server umount lustre-MDT0000 complete [ 3302.370439] LustreError: 100530:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3302.388917] LustreError: 100530:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 57 previous similar messages [ 3304.648021] Lustre: Failing over lustre-MDT0001 [ 3304.658548] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3304.671349] LustreError: Skipped 4 previous similar messages [ 3305.127361] Lustre: server umount lustre-MDT0001 complete [ 3311.918434] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3322.969603] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3332.964810] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3344.046116] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3357.684553] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3375.075289] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4328fcfd7c [ 3375.307560] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3375.313413] Lustre: Skipped 8 previous similar messages [ 3375.343428] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3375.346676] Lustre: Skipped 4 previous similar messages [ 3379.425605] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3390.250551] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3390.972448] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3390.975628] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:329 to 0x2c0000400:353) [ 3392.947796] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3392.962716] Lustre: Skipped 4 previous similar messages [ 3393.009684] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3393.021480] Lustre: Skipped 4 previous similar messages [ 3393.098625] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3393.100533] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 3397.458991] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3447.292751] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 07:11:51 (1787397111) [ 3461.960240] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 3483.565140] Lustre: 109185:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3509.953603] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3514.473584] Lustre: 110320:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3636.109140] Lustre: Failing over lustre-MDT0000 [ 3636.829022] Lustre: server umount lustre-MDT0000 complete [ 3638.753698] 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 [ 3638.772958] Lustre: Skipped 15 previous similar messages [ 3641.828912] LustreError: 88055:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787397307 with bad export cookie 4603077130832379260 [ 3641.839805] LustreError: 88055:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 14 previous similar messages [ 3641.851217] Lustre: Failing over lustre-MDT0001 [ 3642.522620] Lustre: server umount lustre-MDT0001 complete [ 3648.596672] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3662.329065] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3673.558390] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3686.127590] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3701.434885] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3701.451578] Lustre: lustre-MDT0000: reset Object Index mappings [ 3701.461452] Lustre: Skipped 3 previous similar messages [ 3711.457176] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a4329002f8e [ 3716.425656] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3725.060281] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3725.339506] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 3725.367831] LustreError: Skipped 4 previous similar messages [ 3725.507305] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 3725.510655] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:393 to 0x280000400:417) [ 3730.000642] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3730.698140] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 3730.699619] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 3796.388641] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 07:17:41 (1787397461) [ 3811.894530] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 3834.947893] Lustre: 117158:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3859.394061] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3863.219200] Lustre: 118293:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4018.910826] Lustre: Failing over lustre-MDT0000 [ 4019.400837] Lustre: server umount lustre-MDT0000 complete [ 4022.754558] LustreError: 87037:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4022.778661] LustreError: 87037:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 11 previous similar messages [ 4023.790758] LustreError: 16429:0:(client.c:1381:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff92ea4a6a8380 x1874218547097088/t0(0) o38->lustre-MDT0000-lwp-MDT0001@0@lo:12/10 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'ptlrpcd_00_03.0' uid:0 gid:0 projid:4294967295 [ 4023.797485] Lustre: Failing over lustre-MDT0001 [ 4023.800473] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4023.800483] LustreError: Skipped 1 previous similar message [ 4024.513761] Lustre: server umount lustre-MDT0001 complete [ 4031.666515] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4044.062947] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4045.094238] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787397694/real 1787397694] req@ffff92ea42c5d880 x1874218547098624/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787397710 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4045.129251] Lustre: 16430:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 4056.550492] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4067.919498] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4082.480937] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4093.883563] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4093.897329] Lustre: Skipped 3 previous similar messages [ 4093.948044] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4093.952920] Lustre: Skipped 1 previous similar message [ 4099.999925] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4109.518610] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4110.066665] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4110.081176] Lustre: Skipped 1 previous similar message [ 4110.146350] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 4110.169696] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 4113.193240] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4113.208503] Lustre: Skipped 16 previous similar messages [ 4113.247930] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 4113.267692] Lustre: Skipped 1 previous similar message [ 4113.357490] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 4113.385901] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 4116.646647] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4127.813377] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32043: rc = 0 [ 4127.821932] Lustre: *** cfs_fail_loc=190, val=1*** [ 4127.847121] Lustre: Skipped 64 previous similar messages [ 4131.198304] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32036 with flags 0x52: rc = 0 [ 4140.298871] Lustre: Failing over lustre-MDT0000 [ 4140.804547] Lustre: server umount lustre-MDT0000 complete [ 4145.223366] Lustre: Failing over lustre-MDT0001 [ 4145.603342] Lustre: server umount lustre-MDT0001 complete [ 4156.059987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4170.719672] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb6a675c00 x1874218547140096/t0(0) o250->MGC192.168.202.111@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 [ 4176.004324] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4185.981742] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4186.519043] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 4186.545266] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 4191.841043] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 4191.844735] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:513) [ 4192.247800] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4199.359552] Lustre: Failing over lustre-MDT0000 [ 4199.579901] Lustre: server umount lustre-MDT0000 complete [ 4203.567449] Lustre: Failing over lustre-MDT0001 [ 4203.868151] Lustre: server umount lustre-MDT0001 complete [ 4213.453846] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4213.595186] Lustre: *** cfs_fail_loc=190, val=1*** [ 4213.599472] Lustre: Skipped 30 previous similar messages [ 4228.578935] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92ea4f52ea00 x1874218547169664/t0(0) o250->MGC192.168.202.111@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 [ 4235.003624] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4244.376987] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4244.936457] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 4244.962204] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 4250.215825] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:545) [ 4250.223370] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:545) [ 4251.644659] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4270.939509] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 07:25:35 (1787397935) [ 4288.414477] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 4310.940423] Lustre: 128188:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4337.530535] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4373.379672] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 07:27:18 (1787398038) [ 4379.926532] Lustre: *** cfs_fail_loc=195, val=0*** [ 4380.428875] Lustre: *** cfs_fail_loc=195, val=0*** [ 4380.432558] Lustre: Skipped 47 previous similar messages [ 4385.524783] Lustre: Failing over lustre-OST0000 [ 4385.778640] Lustre: server umount lustre-OST0000 complete [ 4388.326679] 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 [ 4388.331861] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4388.348271] Lustre: Skipped 24 previous similar messages [ 4388.367650] LustreError: Skipped 5 previous similar messages [ 4398.100466] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4406.678224] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4598.620946] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 07:31:03 (1787398263) [ 4602.437917] Lustre: *** cfs_fail_loc=196, val=0*** [ 4602.439829] Lustre: Skipped 15 previous similar messages [ 4607.542542] Lustre: Failing over lustre-OST0000 [ 4607.700784] Lustre: server umount lustre-OST0000 complete [ 4617.060036] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4617.361301] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4623.797604] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4816.676382] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 07:34:41 (1787398481) [ 4824.086686] Lustre: *** cfs_fail_loc=196, val=0*** [ 4824.088453] Lustre: Skipped 63 previous similar messages [ 4828.364967] Lustre: *** cfs_fail_loc=196, val=0*** [ 4828.379048] Lustre: Skipped 351 previous similar messages [ 4844.001791] Lustre: Failing over lustre-OST0000 [ 4844.103060] Lustre: server umount lustre-OST0000 complete [ 4844.511806] LustreError: 88046:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4844.535407] LustreError: 88046:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 45 previous similar messages [ 4855.029861] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4855.330833] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4855.345789] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4855.350878] Lustre: Skipped 4 previous similar messages [ 4856.740201] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4856.762194] Lustre: Skipped 4 previous similar messages [ 4856.811985] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4856.812151] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4856.835051] Lustre: Skipped 4 previous similar messages [ 4856.846744] Lustre: Skipped 18 previous similar messages [ 4863.410188] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4879.841467] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4880.873959] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4880.899953] Lustre: Skipped 1 previous similar message [ 4883.703314] Lustre: server umount lustre-MDT0000 complete [ 4887.273033] LustreError: 75823:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787398553 with bad export cookie 4603077130833293257 [ 4887.274703] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4887.283339] LustreError: 75823:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 16 previous similar messages [ 4887.299612] LustreError: Skipped 2 previous similar messages [ 4887.836608] Lustre: server umount lustre-MDT0001 complete [ 4902.005671] Lustre: server umount lustre-OST0000 complete [ 4915.943777] Lustre: server umount lustre-OST0001 complete [ 4927.969590] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 07:36:32 (1787398592) [ 4946.191723] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_hostid [ 4955.205746] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 5001.969442] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 5013.254355] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5013.686883] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5013.721652] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5013.863432] Lustre: lustre-MDT0000: new disk, initializing [ 5013.941432] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5013.944657] Lustre: Skipped 6 previous similar messages [ 5013.962879] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5019.634407] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5031.758665] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5031.863216] Lustre: 139502: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 [ 5031.876406] Lustre: 139502:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 5031.912472] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5031.917232] Lustre: Skipped 1 previous similar message [ 5031.991407] Lustre: lustre-MDT0001: new disk, initializing [ 5032.052530] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5032.065774] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5037.428072] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5042.618286] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5051.356825] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5051.619118] Lustre: lustre-OST0000: new disk, initializing [ 5051.622824] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5051.629825] Lustre: 141133:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5052.714947] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5052.722323] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5052.854831] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5058.573993] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5070.644680] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5070.826208] Lustre: lustre-OST0001: new disk, initializing [ 5070.829754] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5070.834253] Lustre: 142004:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5072.205297] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5072.220403] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5072.327356] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5078.060654] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5087.508794] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5090.958967] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5110.425258] Lustre: Failing over lustre-MDT0000 [ 5110.671483] Lustre: server umount lustre-MDT0000 complete [ 5113.312337] 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 [ 5113.328399] Lustre: Skipped 9 previous similar messages [ 5114.131180] LustreError: 139495:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787398780 with bad export cookie 4603077130833411578 [ 5114.140423] Lustre: Failing over lustre-MDT0001 [ 5114.164677] LustreError: 139495:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 5114.470450] Lustre: server umount lustre-MDT0001 complete [ 5120.245662] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5133.830220] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5134.815124] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787398784/real 1787398784] req@ffff92eb76036a00 x1874218547721472/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787398800 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5134.858315] Lustre: 16432:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 5148.041346] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5160.837253] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5174.664426] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5174.694205] Lustre: lustre-MDT0000: reset Object Index mappings [ 5174.697578] Lustre: Skipped 3 previous similar messages [ 5185.055593] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb76037800 x1874218547725184/t0(0) o250->MGC192.168.202.111@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 [ 5189.863540] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5199.451419] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5199.724634] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5199.736256] LustreError: Skipped 3 previous similar messages [ 5199.939692] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 5199.940230] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 5204.104392] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 5204.104438] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 5206.497446] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5265.366698] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 07:42:09 (1787398929) [ 5282.048121] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 5303.929419] Lustre: 150285:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5332.637386] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5337.030820] Lustre: 151422:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5366.269416] Lustre: Failing over lustre-MDT0000 [ 5366.295364] Lustre: *** cfs_fail_loc=199, val=0*** [ 5366.314199] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5366.328348] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5366.345347] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5366.367536] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5366.384112] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5366.409921] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5366.427559] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5366.439924] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5366.457082] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5366.482934] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5366.498253] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5366.512878] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5366.531253] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5366.542639] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5366.553293] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5366.568528] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5366.576131] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5366.590619] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5366.600281] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5366.608258] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5366.615517] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5366.623415] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5366.629913] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5366.637686] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5366.645915] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5366.652948] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5366.658817] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5366.664768] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5366.675799] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5366.690148] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5366.700694] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5366.710262] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5366.715842] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5366.720919] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5366.727228] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5366.736396] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5366.741677] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5366.756050] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5366.779426] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5366.788615] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5366.794816] Lustre: *** cfs_fail_loc=199, val=0*** [ 5366.797103] Lustre: Skipped 39 previous similar messages [ 5366.800378] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5366.812034] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5366.826592] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5366.843552] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5366.853649] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5366.861315] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5366.867924] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5366.875891] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5366.885061] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5366.896487] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5366.904640] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5366.916074] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5366.934452] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5366.952394] Lustre: 151756:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5367.442692] Lustre: server umount lustre-MDT0000 complete [ 5372.055754] LustreError: 142015:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787399037 with bad export cookie 4603077130833428301 [ 5372.059239] Lustre: Failing over lustre-MDT0001 [ 5372.075107] LustreError: 142015:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 5372.095280] Lustre: *** cfs_fail_loc=199, val=0*** [ 5372.104060] Lustre: Skipped 13 previous similar messages [ 5372.106193] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5372.114985] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5372.124424] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5372.132040] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5372.146971] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5372.155271] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5372.162231] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5372.166802] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5372.171715] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5372.179373] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5372.186461] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5372.191207] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5372.197471] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5372.204139] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5372.213910] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5372.219541] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5372.224588] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5372.229461] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5372.235979] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5372.242056] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5372.255159] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5372.262342] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5372.269854] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5372.277942] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5372.285607] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5372.292084] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5372.299040] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5372.310958] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5372.324699] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5372.332510] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5372.339313] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5372.348328] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5372.356788] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5372.363520] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5372.368329] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5372.372809] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5372.378161] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5372.386926] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5372.395918] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5372.406225] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5372.412823] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5372.420439] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5372.427399] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5372.433411] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5372.443428] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5372.450097] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5372.455971] Lustre: 151957:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5372.986957] Lustre: server umount lustre-MDT0001 complete [ 5382.877892] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5382.974184] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5382.984961] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5382.993885] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5383.003308] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5383.014361] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5383.032179] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5383.051311] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5383.063288] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5383.078552] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5383.089639] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5383.101489] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5383.116509] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5383.133831] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5383.163933] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5383.182300] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5383.197459] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5383.206432] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5383.225362] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5383.237901] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5383.252358] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5383.269971] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5383.292457] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5383.311341] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5383.331836] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5383.347905] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5383.369948] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5383.391568] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5383.428312] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5383.464861] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5383.480489] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5383.498206] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5383.508271] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5383.522071] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5383.538889] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5383.553031] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5383.580404] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5383.602911] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5383.620103] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5383.646871] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5383.677310] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5383.698044] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5383.710849] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5383.757544] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5383.782939] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5383.818215] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5383.860859] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5383.881397] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5383.904789] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5383.921601] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5383.934353] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5383.961274] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5383.983768] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5384.008806] Lustre: 152454:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5402.778595] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5412.361454] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5412.509117] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5412.521908] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5412.543228] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5412.575899] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5412.591593] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5412.611207] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5412.637512] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5412.647525] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5412.665509] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5412.682476] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5412.698557] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5412.732423] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5412.759352] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5412.775262] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5412.782770] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5412.795729] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5412.815330] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5412.832787] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5412.850855] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5412.871524] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5412.893957] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5412.920660] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5412.943137] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5412.965228] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5412.972896] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5412.985877] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5412.997768] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5413.008777] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5413.023334] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5413.038304] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5413.049367] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5413.058682] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5413.068439] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5413.083310] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5413.101625] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5413.110364] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5413.118344] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5413.130967] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5413.138439] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5413.148675] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5413.158869] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5413.172437] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5413.184976] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5413.196724] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5413.206072] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5413.216333] Lustre: 153200:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5413.344042] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 5413.359042] Lustre: Skipped 3 previous similar messages [ 5413.593427] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 5413.598417] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 5418.876785] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5419.077091] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 5419.077152] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 5430.888505] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 07:44:55 (1787399095) [ 5432.164521] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5432.173771] Lustre: Skipped 123 previous similar messages [ 5434.533866] Lustre: Failing over lustre-MDT0000 [ 5435.140206] Lustre: server umount lustre-MDT0000 complete [ 5444.577338] LustreError: 152467:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5444.632129] LustreError: 152467:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 39 previous similar messages [ 5454.407760] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5454.817384] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 5454.829395] Lustre: Skipped 3 previous similar messages [ 5458.407237] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5458.427740] Lustre: Skipped 2 previous similar messages [ 5460.353985] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5460.485129] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5460.497112] Lustre: Skipped 11 previous similar messages [ 5460.553500] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 5460.577121] Lustre: Skipped 2 previous similar messages [ 5460.649444] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 5460.651048] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 5464.647525] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 07:45:28 (1787399128) [ 5466.356750] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5469.152573] Lustre: Failing over lustre-MDT0000 [ 5469.557429] Lustre: server umount lustre-MDT0000 complete [ 5489.176859] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5496.763961] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5496.770876] Lustre: Skipped 3 previous similar messages [ 5502.025441] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:193) [ 5502.028492] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 5502.588893] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5506.430344] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 07:46:11 (1787399171) [ 5529.451633] Lustre: Failing over lustre-MDT0000 [ 5529.734616] Lustre: server umount lustre-MDT0000 complete [ 5533.586286] Lustre: Failing over lustre-MDT0001 [ 5533.586619] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5533.617708] LustreError: Skipped 4 previous similar messages [ 5534.078143] Lustre: server umount lustre-MDT0001 complete [ 5542.606476] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5543.839314] LustreError: 157247:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 5543.865038] LustreError: 157247:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff92eb7f56c700 x1874218548077568/t0(0) o250->MGC192.168.202.111@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1787399209 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 5543.904746] LustreError: 157247:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 5543.926453] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb81f1f100 x1874218548078976/t0(0) o250->MGC192.168.202.111@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 [ 5549.092944] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5558.031366] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5558.480367] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5558.488088] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 5563.257141] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5563.985783] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5563.985940] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 5569.466507] Lustre: Failing over lustre-MDT0000 [ 5569.714411] Lustre: server umount lustre-MDT0000 complete [ 5573.460978] Lustre: Failing over lustre-MDT0001 [ 5574.008805] Lustre: server umount lustre-MDT0001 complete [ 5583.435269] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5583.466746] Lustre: lustre-MDT0000: reset Object Index mappings [ 5583.471198] Lustre: Skipped 1 previous similar message [ 5583.842929] LustreError: 16429:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff92eb73db6a00 x1874218548107264/t0(0) o250->MGC192.168.202.111@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 [ 5589.840296] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5599.721214] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5600.149550] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 5600.156727] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5605.225379] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5605.455226] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5605.465414] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:289) [ 5615.648979] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 07:48:00 (1787399280) [ 5625.835913] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5625.840515] Lustre: Skipped 3 previous similar messages [ 5631.624411] Lustre: server umount lustre-MDT0000 complete [ 5636.642991] Lustre: server umount lustre-MDT0001 complete [ 5651.658882] Lustre: server umount lustre-OST0000 complete [ 5665.541086] Lustre: server umount lustre-OST0001 complete [ 5673.101786] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5682.269832] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5697.887421] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5703.008605] LustreError: 161974:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.111@tcp: failed processing log, type 4: rc = -110 [ 5728.735193] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5728.739601] Lustre: Skipped 13 previous similar messages [ 5734.256977] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5739.545914] Lustre: Failing over lustre-OST0000 [ 5739.797863] Lustre: server umount lustre-OST0000 complete [ 5745.954181] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5755.164450] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5770.719688] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5775.847281] LustreError: 163500:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.111@tcp: failed processing log, type 4: rc = -110 [ 5807.691737] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5815.603684] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 07:51:20 (1787399480) [ 5828.103532] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 5838.142809] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5838.538151] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5843.501944] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5852.205730] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5852.819210] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5857.030052] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5860.279715] Lustre: 166406:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5874.635683] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5880.328253] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 5880.346885] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:257) [ 5882.021211] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5889.839316] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5895.649217] Lustre: *** cfs_fail_loc=193, val=0*** [ 5897.468249] Lustre: Failing over lustre-MDT0000 [ 5897.828325] Lustre: server umount lustre-MDT0000 complete [ 5898.719526] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5898.729781] LustreError: Skipped 7 previous similar messages [ 5898.733446] 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 [ 5898.746158] Lustre: Skipped 32 previous similar messages [ 5906.455570] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5906.745575] Lustre: *** cfs_fail_loc=193, val=0*** [ 5906.747443] Lustre: Skipped 1 previous similar message [ 5912.100246] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 5912.100791] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5912.105116] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5912.161407] Lustre: *** cfs_fail_loc=193, val=0*** [ 5912.162961] Lustre: Skipped 3 previous similar messages [ 5916.167915] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5916.168118] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5916.172312] Lustre: Skipped 57 previous similar messages [ 5923.383798] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5923.385019] Lustre: Skipped 3 previous similar messages [ 5933.077471] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 07:53:17 (1787399597) [ 5936.279906] Lustre: Failing over lustre-MDT0000 [ 5936.796717] Lustre: server umount lustre-MDT0000 complete [ 5942.111985] LustreError: 163508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787399608 with bad export cookie 4603077130833513225 [ 5942.126061] Lustre: Failing over lustre-MDT0001 [ 5942.126876] LustreError: 163508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 9 previous similar messages [ 5942.598826] Lustre: server umount lustre-MDT0001 complete [ 5945.308965] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5953.387150] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5958.111206] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787399608/real 1787399608] req@ffff92eb476c5880 x1874218548264448/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787399624 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5958.139359] Lustre: 16433:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 47 previous similar messages [ 5967.392691] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x3fe16a43290e50c7 [ 5971.564941] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5978.755682] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5981.065456] LustreError: 170906:0:(update_trans.c:1070:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5981.151648] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:289) [ 5981.159208] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 5981.879688] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5981.882616] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 5984.242783] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5990.704971] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5997.699389] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 07:54:22 (1787399662) [ 6002.660615] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6002.668046] Lustre: Skipped 4 previous similar messages [ 6007.796578] Lustre: server umount lustre-MDT0000 complete [ 6011.786413] Lustre: server umount lustre-MDT0001 complete [ 6025.332267] Lustre: server umount lustre-OST0000 complete [ 6039.131825] Lustre: server umount lustre-OST0001 complete [ 6046.016676] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6059.044938] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6059.812702] LustreError: 173268:0:(ldlm_lib.c:1179: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. [ 6059.838087] LustreError: 173268:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 118 previous similar messages [ 6064.879465] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6070.852794] Lustre: Failing over lustre-MDT0000 [ 6070.866307] LustreError: 173301:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6070.877768] LustreError: 173301:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6070.886529] LustreError: 173301:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 11, retries 0, failed: rc = -5 [ 6071.377536] Lustre: server umount lustre-MDT0000 complete [ 6078.199342] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6092.973261] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6098.569823] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6106.263357] Lustre: DEBUG MARKER: === sanity-scrub: start setup 07:56:11 (1787399771) === [ 6108.222227] LustreError: 174939:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6108.232384] LustreError: 174939:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6108.243552] LustreError: 174939:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 15, retries 0, failed: rc = -5 [ 6108.739436] Lustre: server umount lustre-MDT0000 complete [ 6142.317913] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_hostid [ 6150.991386] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 6202.116642] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing load_modules_local [ 6213.041537] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6213.258599] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6213.310335] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6213.369398] Lustre: lustre-MDT0000: new disk, initializing [ 6213.451263] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6217.341528] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6229.877259] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6229.967949] Lustre: 180302: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 [ 6229.987728] Lustre: 180302:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 6230.013652] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6230.019658] Lustre: Skipped 1 previous similar message [ 6230.094623] Lustre: lustre-MDT0001: new disk, initializing [ 6230.188634] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6230.214797] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6234.172132] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6238.872605] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6247.749073] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6247.912177] Lustre: lustre-OST0000: new disk, initializing [ 6247.915735] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6247.921701] Lustre: 182239:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6249.382106] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6249.409688] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6249.497705] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6254.909135] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6269.057250] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6269.221975] Lustre: lustre-OST0001: new disk, initializing [ 6269.226959] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6269.236877] Lustre: 183263:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6270.477703] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6270.493767] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6270.572291] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6275.516243] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6283.929888] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6287.444833] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6292.585428] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 07:59:17 (1787399957) === [ 6294.258502] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 6015 sec ========= 07:59:19 (1787399959) [ 6296.191264] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 07:59:20 (1787399960) === [ 6299.376452] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 07:59:24 (1787399964) === [ 6306.282508] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6306.306080] Lustre: Skipped 7 previous similar messages [ 6310.207115] Lustre: server umount lustre-MDT0000 complete [ 6319.497389] LustreError: MGC192.168.202.111@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6319.504039] LustreError: Skipped 5 previous similar messages [ 6320.025377] Lustre: server umount lustre-MDT0001 complete [ 6339.163397] Lustre: server umount lustre-OST0000 complete [ 6347.298484] Lustre: server umount lustre-OST0001 complete [ 6363.059209] Lustre: DEBUG MARKER: oleg211-server.virtnet: executing unload_modules_local [ 6366.331938] Key type lgssc unregistered [ 6366.685840] LNet: 186674:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6366.693347] LNetError: 186674:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6366.707549] LNet: Removed LNI 192.168.202.111@tcp [ 6367.803307] Key type .llcrypt unregistered [ 6367.805195] Key type ._llcrypt unregistered