[ 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 499199946 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.001010] APIC: Switch to symmetric I/O mode setup [ 0.002319] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004015] kvm-guest: setup PV IPIs [ 0.006928] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008010] pid_max: default: 32768 minimum: 301 [ 0.009116] LSM: Security Framework initializing [ 0.010044] Yama: becoming mindful. [ 0.010883] SELinux: Initializing. [ 0.011061] *** VALIDATE selinux *** [ 0.018417] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.023062] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.024141] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.025095] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026094] *** VALIDATE tmpfs *** [ 0.027417] *** VALIDATE proc *** [ 0.028199] *** VALIDATE cgroup *** [ 0.029007] *** VALIDATE cgroup2 *** [ 0.030231] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.031141] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.032007] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.033024] Spectre V2 : User space: Vulnerable [ 0.034007] Speculative Store Bypass: Vulnerable [ 0.036704] debug: unmapping init [mem 0xffffffffa8459000-0xffffffffa8460fff] [ 0.038726] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.039584] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.040021] ... version: 2 [ 0.041010] ... bit width: 48 [ 0.042009] ... generic registers: 4 [ 0.043011] ... value mask: 0000ffffffffffff [ 0.044016] ... max period: 00007fffffffffff [ 0.045015] ... fixed-purpose events: 3 [ 0.046015] ... event mask: 000000070000000f [ 0.047299] rcu: Hierarchical SRCU implementation. [ 0.049493] smp: Bringing up secondary CPUs ... [ 0.050493] x86: Booting SMP configuration: [ 0.051020] .... node #0, CPUs: #1 #2 #3 [ 0.056103] smp: Brought up 1 node, 4 CPUs [ 0.058014] smpboot: Max logical packages: 1 [ 0.059020] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.212465] node 0 deferred pages initialised in 149ms [ 0.216008] devtmpfs: initialized [ 0.217241] x86/mm: Memory block size: 128MB [ 0.221179] gcov: version magic: 0x41383552 [ 0.224230] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.225063] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.227382] pinctrl core: initialized pinctrl subsystem [ 0.230303] [ 0.231010] ************************************************************* [ 0.234017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.236013] ** ** [ 0.237012] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.239017] ** ** [ 0.242020] ** This means that this kernel is built to expose internal ** [ 0.244019] ** IOMMU data structures, which may compromise security on ** [ 0.247019] ** your system. ** [ 0.251019] ** ** [ 0.253017] ** If you see this message and you are not debugging the ** [ 0.256020] ** kernel, report this immediately to your vendor! ** [ 0.258016] ** ** [ 0.260017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.263017] ************************************************************* [ 0.265809] NET: Registered protocol family 16 [ 0.268510] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.271082] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.273079] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.277147] cpuidle: using governor menu [ 0.278961] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.281811] PCI: Using configuration type 1 for base access [ 0.284153] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.294126] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.298040] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.303083] cryptd: max_cpu_qlen set to 1000 [ 0.307560] ACPI: Added _OSI(Module Device) [ 0.309025] ACPI: Added _OSI(Processor Device) [ 0.311017] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.313020] ACPI: Added _OSI(Processor Aggregator Device) [ 0.318376] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.325482] ACPI: Interpreter enabled [ 0.328070] ACPI: PM: (supports S0 S3 S4 S5) [ 0.330018] ACPI: Using IOAPIC for interrupt routing [ 0.333112] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.339458] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.352960] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.359063] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.361043] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.365095] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.370432] acpiphp: Slot [2] registered [ 0.372122] acpiphp: Slot [5] registered [ 0.375223] acpiphp: Slot [6] registered [ 0.377176] acpiphp: Slot [7] registered [ 0.379290] acpiphp: Slot [8] registered [ 0.381128] acpiphp: Slot [9] registered [ 0.384171] acpiphp: Slot [10] registered [ 0.386145] acpiphp: Slot [3] registered [ 0.389137] acpiphp: Slot [4] registered [ 0.391159] acpiphp: Slot [11] registered [ 0.393129] acpiphp: Slot [12] registered [ 0.396134] acpiphp: Slot [13] registered [ 0.398143] acpiphp: Slot [14] registered [ 0.400147] acpiphp: Slot [15] registered [ 0.403126] acpiphp: Slot [16] registered [ 0.405200] acpiphp: Slot [17] registered [ 0.407172] acpiphp: Slot [18] registered [ 0.408133] acpiphp: Slot [19] registered [ 0.410215] acpiphp: Slot [20] registered [ 0.412174] acpiphp: Slot [21] registered [ 0.413129] acpiphp: Slot [22] registered [ 0.415144] acpiphp: Slot [23] registered [ 0.416147] acpiphp: Slot [24] registered [ 0.418168] acpiphp: Slot [25] registered [ 0.420157] acpiphp: Slot [26] registered [ 0.421152] acpiphp: Slot [27] registered [ 0.423174] acpiphp: Slot [28] registered [ 0.424174] acpiphp: Slot [29] registered [ 0.426155] acpiphp: Slot [30] registered [ 0.427213] acpiphp: Slot [31] registered [ 0.429072] PCI host bridge to bus 0000:00 [ 0.430023] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.432142] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.435031] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.437043] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.440046] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.444058] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.447192] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.451112] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.455247] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.465019] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.470538] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.473023] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.475022] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.478030] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.483183] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.485797] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.489065] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.491918] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.498026] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.512038] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.518027] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.525299] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.534022] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.540021] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.557021] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.568556] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.580020] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.587021] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.609017] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.620403] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.626024] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.633021] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.647031] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.654525] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.664016] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.671015] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.697017] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.714091] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.721022] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.732018] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.751026] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.763762] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.771022] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.778026] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.815021] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.826802] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.829438] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.832438] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.835411] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.837240] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.843037] iommu: Default domain type: Passthrough [ 0.845441] SCSI subsystem initialized [ 0.847339] ACPI: bus type USB registered [ 0.849073] usbcore: registered new interface driver usbfs [ 0.850080] usbcore: registered new interface driver hub [ 0.852122] usbcore: registered new device driver usb [ 0.854178] pps_core: LinuxPPS API ver. 1 registered [ 0.857018] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.860069] PTP clock support registered [ 0.863189] EDAC MC: Ver: 3.0.0 [ 0.865559] PCI: Using ACPI for IRQ routing [ 0.867911] NetLabel: Initializing [ 0.869016] NetLabel: domain hash size = 128 [ 0.871016] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.872088] NetLabel: unlabeled traffic allowed by default [ 0.875054] vgaarb: loaded [ 0.877149] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.878014] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.886736] clocksource: Switched to clocksource kvm-clock [ 1.001982] VFS: Disk quotas dquot_6.6.0 [ 1.004418] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.006840] *** VALIDATE ramfs *** [ 1.007973] *** VALIDATE hugetlbfs *** [ 1.009393] pnp: PnP ACPI init [ 1.011675] pnp: PnP ACPI: found 6 devices [ 1.045337] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.049299] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.052125] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.054980] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.057746] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.060636] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.063939] NET: Registered protocol family 2 [ 1.066659] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.072305] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.075755] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.081181] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.085479] TCP: Hash tables configured (established 65536 bind 65536) [ 1.088708] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.091676] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.094345] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.096793] NET: Registered protocol family 1 [ 1.100405] RPC: Registered named UNIX socket transport module. [ 1.102832] RPC: Registered udp transport module. [ 1.104450] RPC: Registered tcp transport module. [ 1.106075] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.108934] NET: Registered protocol family 44 [ 1.110534] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.112917] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.114836] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.117356] PCI: CLS 0 bytes, default 64 [ 1.118964] Unpacking initramfs... [ 2.561164] debug: unmapping init [mem 0xffff9b5efcc54000-0xffff9b5efffbffff] [ 2.568474] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.571019] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.575054] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.092063] Initialise system trusted keyrings [ 3.093769] Key type blacklist registered [ 3.095575] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.104723] zbud: loaded [ 3.108158] *** VALIDATE nfs *** [ 3.109317] *** VALIDATE nfs4 *** [ 3.110919] pstore: using deflate compression [ 3.114507] Platform Keyring initialized [ 3.222643] NET: Registered protocol family 38 [ 3.224170] Key type asymmetric registered [ 3.225568] Asymmetric key parser 'x509' registered [ 3.227474] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.230691] io scheduler mq-deadline registered [ 3.232446] io scheduler kyber registered [ 3.234086] io scheduler bfq registered [ 3.236053] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.239476] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.242881] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.246237] ACPI: Power Button [PWRF] [ 3.251260] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.259382] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.278086] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.285227] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.306193] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.335633] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.363523] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.369383] Non-volatile memory driver v1.3 [ 3.371098] Linux agpgart interface v0.103 [ 3.403554] virtio_blk virtio1: [vda] 145920 512-byte logical blocks (74.7 MB/71.3 MiB) [ 3.406196] vda: detected capacity change from 0 to 74711040 [ 3.421235] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.424557] vdb: detected capacity change from 0 to 1073741824 [ 3.440021] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.443875] vdc: detected capacity change from 0 to 2621440000 [ 3.469861] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.473240] vdd: detected capacity change from 0 to 2621440000 [ 3.491369] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.494647] vde: detected capacity change from 0 to 4294967296 [ 3.512194] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.515174] vdf: detected capacity change from 0 to 4294967296 [ 3.528987] libphy: Fixed MDIO Bus: probed [ 3.535274] usbcore: registered new interface driver usbserial_generic [ 3.538472] usbserial: USB Serial support registered for generic [ 3.541885] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.546711] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.548717] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.550988] mousedev: PS/2 mouse device common for all mice [ 3.554234] rtc_cmos 00:05: RTC can wake from S4 [ 3.557918] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.561957] rtc_cmos 00:05: registered as rtc0 [ 3.564172] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.565398] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.570489] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.573531] intel_pstate: CPU model not supported [ 3.579375] hid: raw HID events driver (C) Jiri Kosina [ 3.581587] usbcore: registered new interface driver usbhid [ 3.583730] usbhid: USB HID core driver [ 3.585730] drop_monitor: Initializing network drop monitor service [ 3.588305] Initializing XFRM netlink socket [ 3.590636] NET: Registered protocol family 10 [ 3.594019] Segment Routing with IPv6 [ 3.596124] NET: Registered protocol family 17 [ 3.598777] mpls_gso: MPLS GSO support [ 3.605371] RAS: Correctable Errors collector initialized. [ 3.607753] AVX version of gcm_enc/dec engaged. [ 3.609616] AES CTR mode by8 optimization enabled [ 3.697685] sched_clock: Marking stable (3697660366, 0)->(4555240683, -857580317) [ 3.701340] registered taskstats version 1 [ 3.704946] Loading compiled-in X.509 certificates [ 3.707686] zswap: loaded using pool lzo/zbud [ 3.734573] Key type big_key registered [ 3.746733] Key type encrypted registered [ 3.748643] ima: No TPM chip found, activating TPM-bypass! [ 3.750881] ima: Allocated hash algorithm: sha1 [ 3.752704] ima: No architecture policies found [ 3.754356] evm: Initialising EVM extended attributes: [ 3.756445] evm: security.selinux [ 3.757753] evm: security.ima [ 3.758930] evm: security.capability [ 3.760273] evm: HMAC attrs: 0x1 [ 3.762978] rtc_cmos 00:05: setting system clock to 2026-08-14 22:24:29 UTC (1786746269) [ 3.769708] debug: unmapping init [mem 0xffffffffa9403000-0xffffffffa95fffff] [ 3.773073] debug: unmapping init [mem 0xffffffffa8182000-0xffffffffa8458fff] [ 3.782234] Write protecting the kernel read-only data: 28672k [ 3.787629] debug: unmapping init [mem 0xffffffffa6803000-0xffffffffa69fffff] [ 3.791407] debug: unmapping init [mem 0xffffffffa7114000-0xffffffffa71fffff] [ 3.831716] 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.843138] systemd[1]: Detected virtualization kvm. [ 3.845060] systemd[1]: Detected architecture x86-64. [ 3.847100] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.877363] systemd[1]: No hostname configured. [ 3.879471] systemd[1]: Set hostname to . [ 3.882115] random: systemd: uninitialized urandom read (16 bytes read) [ 3.885099] systemd[1]: Initializing machine ID from random generator. [ 4.033896] random: systemd: uninitialized urandom read (16 bytes read) [ 4.037220] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 4.041700] random: systemd: uninitialized urandom read (16 bytes read) [ 4.045092] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 4.049802] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Journal Service... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Swap. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.673621] device-mapper: uevent: version 1.0.3 [ 4.676271] 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. [ 4.998191] random: fast init done 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. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.471733] virtio_net virtio0 ens2: renamed from eth0 [ 5.488740] scsi host0: ata_piix [ 5.559684] scsi host1: ata_piix [ 5.561500] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.565647] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.274634] dracut-initqueue[592]: RTNETLINK answers: File exists [ 10.266037] random: crng init done [ 10.267251] 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.692720] 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... 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 target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.820935] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.078236] SELinux: Disabled at runtime. [ 12.136760] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.145943] systemd[1]: Detected virtualization kvm. [ 12.147884] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.650369] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.653933] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.658949] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.663436] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.666836] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.673459] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.682240] systemd[1]: Listening on RPCbind Server Activation Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Mounting POSIX Message Queue File System... [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Kernel Debug File System... Activating swap /dev/disk/by-label/SWAP... Mounting Huge Pages File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. Starting Apply Kernel Variables... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK [[ 12.750792] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS 0m] Listening on udev Control Socket. Starting udev Coldplug all Devices... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. Starting Remount Root and Kernel File Systems... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Process Core Dump Socket. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Created slice system-getty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.095396] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.342689] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.466666] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.520375] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.536645] EDAC sbridge: Ver: 1.1.2 [ 15.183939] Key type dns_resolver registered [ 15.498384] NFS: Registering the id_resolver key type [ 15.500753] Key type id_resolver registered [ 15.502516] 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 Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started 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. [ OK ] Started Authorization Manager. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg607-server login: [ 41.712230] libcfs: loading out-of-tree module taints kernel. [ 41.732307] Key type ._llcrypt registered [ 41.733755] Key type .llcrypt registered [ 41.777981] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_hostid [ 55.655642] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 57.198703] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 57.212907] alg: No test for adler32 (adler32-zlib) [ 58.576795] Lustre: Lustre: Build Version: 2.17.57_3_g6085841 [ 59.374106] LNet: Added LNI 192.168.206.107@tcp [8/256/0/180] [ 61.161880] Key type lgssc registered [ 62.804393] Lustre: Echo OBD driver; http://www.lustre.org/ [ 76.596493] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 118.217104] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 131.187368] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 131.210484] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 132.514672] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 132.551553] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 132.666978] Lustre: lustre-MDT0000: new disk, initializing [ 132.796743] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 132.832507] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 138.242931] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 152.237919] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 152.375104] Lustre: 6512: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 [ 152.411627] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 152.415285] Lustre: Skipped 1 previous similar message [ 152.535366] Lustre: lustre-MDT0001: new disk, initializing [ 152.607468] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 152.641488] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 152.656354] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 157.047224] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 161.534625] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 170.522230] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 170.790430] Lustre: lustre-OST0000: new disk, initializing [ 170.792793] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 170.800572] Lustre: 8452:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 170.887484] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 173.136335] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 173.143893] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 173.223135] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 176.523738] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 184.578009] hrtimer: interrupt took 1951743 ns [ 191.609405] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 191.709230] Lustre: lustre-OST0001: new disk, initializing [ 191.712243] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 191.717332] Lustre: 9523:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 191.765617] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 198.682502] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 199.758490] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 199.779925] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 199.866940] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 210.899534] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 219.480580] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 225.809429] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing check_logdir /tmp/testlogs/ [ 230.521505] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing yml_node [ 234.635603] Lustre: DEBUG MARKER: Client: 2.17.57.3 [ 236.854837] Lustre: DEBUG MARKER: MDS: 2.17.57.3 [ 239.364789] Lustre: DEBUG MARKER: OSS: 2.17.57.3 [ 240.889468] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Fri Aug 14 18:28:24 EDT 2026 [ 256.098616] Lustre: DEBUG MARKER: excepting tests: [ 266.410833] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 275.425398] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 275.433485] 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 [ 275.467482] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 276.454626] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 276.454978] 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 [ 280.520402] Lustre: server umount lustre-MDT0000 complete [ 286.693054] LustreError: 6521:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 286.714717] LustreError: 6521:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 288.044696] LustreError: 6506:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786746553 with bad export cookie 3326351938387396649 [ 288.049148] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 288.054872] LustreError: 6506:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 288.306318] Lustre: server umount lustre-MDT0001 complete [ 306.570981] Lustre: server umount lustre-OST0000 complete [ 307.424328] Lustre: 3649:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746557/real 1786746557] req@ffff9b5f7c7a6300 x1873539314582528/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746573 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 307.469500] 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 [ 307.486251] Lustre: Skipped 2 previous similar messages [ 310.062042] Lustre: 3650:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746559/real 1786746559] req@ffff9b5f7bcec000 x1873539314582784/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746575 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 312.287108] Lustre: 3648:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746562/real 1786746562] req@ffff9b5f7c7a5180 x1873539314583040/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746578 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 314.095309] Lustre: server umount lustre-OST0001 complete [ 329.561503] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing unload_modules_local [ 332.274797] Key type lgssc unregistered [ 332.601433] LNet: 14799:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 332.610995] LNetError: 14799:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 332.623955] LNet: Removed LNI 192.168.206.107@tcp [ 333.665225] Key type .llcrypt unregistered [ 333.670094] Key type ._llcrypt unregistered [ 357.250945] Key type ._llcrypt registered [ 357.253654] Key type .llcrypt registered [ 357.331811] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_hostid [ 370.153757] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 372.043811] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 372.085350] alg: No test for adler32 (adler32-zlib) [ 373.281914] Lustre: Lustre: Build Version: 2.17.57_3_g6085841 [ 373.595775] LNet: Added LNI 192.168.206.107@tcp [8/256/0/180] [ 375.377472] Key type lgssc registered [ 376.237943] Lustre: Echo OBD driver; http://www.lustre.org/ [ 423.031061] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 433.466832] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 433.484952] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 434.684993] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 434.722948] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 434.816266] Lustre: lustre-MDT0000: new disk, initializing [ 434.883201] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 434.908867] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 438.992723] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 451.507444] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 451.592568] Lustre: 19233: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 [ 451.616541] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 451.620676] Lustre: Skipped 1 previous similar message [ 451.680775] Lustre: lustre-MDT0001: new disk, initializing [ 451.744487] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 451.760982] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 451.780992] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 455.728615] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 460.204549] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 467.921547] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 468.074491] Lustre: lustre-OST0000: new disk, initializing [ 468.080407] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 468.084741] Lustre: 21170:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 468.133136] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 468.817164] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 468.823434] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 468.920525] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 472.590394] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 483.669951] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 483.729441] Lustre: lustre-OST0001: new disk, initializing [ 483.736252] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 483.739958] Lustre: 22197:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 483.792568] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 489.242325] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 490.030489] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 490.047991] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 490.123569] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 500.044058] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 506.453792] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 513.360293] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 18:32:56 (1786746776) === [ 514.930137] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 18:32:58 (1786746778) [ 533.760699] Lustre: Failing over lustre-MDT0000 [ 533.983581] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 533.995973] 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 [ 536.009528] Lustre: server umount lustre-MDT0000 complete [ 536.036560] 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 [ 536.044271] Lustre: Skipped 1 previous similar message [ 539.354718] LustreError: 19227:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786746805 with bad export cookie 12884375591140350 [ 539.355414] Lustre: Failing over lustre-MDT0001 [ 539.356513] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 539.370230] LustreError: 19227:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 539.653101] Lustre: server umount lustre-MDT0001 complete [ 546.688748] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 549.289170] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc64576437bb4 [ 549.303338] Lustre: MGC192.168.206.107@tcp: Connection restored to 0@lo (at 0@lo) [ 549.480795] LustreError: 21163:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 549.500077] LustreError: 21163:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 6 previous similar messages [ 549.554979] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 553.430813] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 554.977461] 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 [ 554.978440] LustreError: 21164:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 554.995669] Lustre: Skipped 1 previous similar message [ 555.023113] LustreError: 21164:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 556.003446] LustreError: 24212:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 556.011024] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 556.034357] LustreError: 24212:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 557.024548] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746806/real 1786746806] req@ffff9b5e437f8380 x1873539643860096/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746822 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 560.102725] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746809/real 1786746809] req@ffff9b5e437f8700 x1873539643860352/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746825 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 560.145749] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 561.122118] LustreError: 24211:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 561.144911] LustreError: 24211:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 561.543737] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 561.747689] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 561.821459] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 561.859583] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 561.868565] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 562.783135] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746811/real 1786746811] req@ffff9b5e437fad80 x1873539643860480/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746827 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 562.813258] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 565.714672] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 565.924365] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746815/real 1786746815] req@ffff9b5e434dea00 x1873539643860864/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746831 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 565.962517] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 567.265225] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 567.272889] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 567.296938] Lustre: Skipped 1 previous similar message [ 567.335772] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 567.390578] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 567.390652] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 576.526618] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 18:34:00 (1786746840) [ 597.179333] Lustre: Failing over lustre-MDT0000 [ 597.392966] Lustre: server umount lustre-MDT0000 complete [ 597.983714] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 597.985877] 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 [ 597.991465] LustreError: 25544:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 597.991476] LustreError: 25544:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 598.026378] Lustre: Skipped 4 previous similar messages [ 600.597607] Lustre: Failing over lustre-MDT0001 [ 600.599944] LustreError: 19225:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786746866 with bad export cookie 12884375591156660 [ 600.600364] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 600.873038] Lustre: server umount lustre-MDT0001 complete [ 608.106977] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 611.232951] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc6457643e6f2 [ 611.242496] Lustre: MGC192.168.206.107@tcp: Connection restored to 0@lo (at 0@lo) [ 611.256937] Lustre: Skipped 2 previous similar messages [ 611.478590] LustreError: 21164:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 611.505533] LustreError: 21164:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 611.545323] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 611.583462] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 615.415575] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 616.938199] 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 [ 618.026863] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 619.039495] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746868/real 1786746868] req@ffff9b5e434dd500 x1873539643974272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746884 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 623.032146] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 623.381564] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 623.517248] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 623.519372] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 627.167157] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786746876/real 1786746876] req@ffff9b5e43496a00 x1873539643975040/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786746892 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 627.185945] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 627.473509] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 628.709236] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 628.713110] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 628.747448] Lustre: Skipped 1 previous similar message [ 628.779424] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 628.840615] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 628.842336] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 631.644561] Lustre: *** cfs_fail_loc=193, val=0*** [ 635.867571] Lustre: Failing over lustre-MDT0000 [ 636.103416] Lustre: server umount lustre-MDT0000 complete [ 638.944203] 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 [ 638.956350] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 638.976198] Lustre: Skipped 1 previous similar message [ 638.978366] LustreError: 27862:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 639.023902] LustreError: 27862:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 12 previous similar messages [ 645.738984] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 645.952312] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 646.316175] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 646.324201] Lustre: Skipped 1 previous similar message [ 646.386671] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 651.745467] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 651.755520] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 651.765814] Lustre: Skipped 2 previous similar messages [ 651.798872] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 651.888723] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 651.890524] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 651.969759] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 661.728870] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 18:35:24 (1786746924) [ 677.451397] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 695.467168] Lustre: 30486:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 715.923973] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 719.287555] Lustre: 31622:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 731.974181] Lustre: *** cfs_fail_loc=198, val=0*** [ 740.967523] Lustre: Failing over lustre-MDT0000 [ 741.143793] Lustre: server umount lustre-MDT0000 complete [ 743.910980] 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 [ 743.913410] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 743.920667] LustreError: 27862:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 743.920680] LustreError: 27862:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 4 previous similar messages [ 743.926571] Lustre: Skipped 4 previous similar messages [ 744.725772] Lustre: Failing over lustre-MDT0001 [ 744.731316] LustreError: 25725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747010 with bad export cookie 12884375591185689 [ 744.731948] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 744.771938] LustreError: 25725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 745.113713] Lustre: server umount lustre-MDT0001 complete [ 749.543985] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 754.127501] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 763.438667] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 764.384689] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786747014/real 1786747014] req@ffff9b5e4aba1f80 x1873539644142336/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786747030 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 764.425499] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 769.927507] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 769.960693] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 774.912153] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 783.334887] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 783.348360] Lustre: Skipped 3 previous similar messages [ 783.689593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 783.820161] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 783.899825] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 783.901321] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 788.981599] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 789.015755] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 789.041172] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 789.065730] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 789.066667] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 804.310395] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 18:37:47 (1786747067) [ 828.037972] Lustre: Failing over lustre-MDT0000 [ 828.497520] Lustre: server umount lustre-MDT0000 complete [ 829.921456] 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 [ 829.926369] LustreError: 33095:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 829.932170] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 829.940376] Lustre: Skipped 6 previous similar messages [ 829.987356] LustreError: 33095:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 16 previous similar messages [ 832.417848] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747098 with bad export cookie 12884375591212982 [ 832.419755] Lustre: Failing over lustre-MDT0001 [ 832.420364] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 832.429286] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 832.747196] Lustre: server umount lustre-MDT0001 complete [ 836.630294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 840.967667] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 848.925196] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 848.949432] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 850.271632] Lustre: 16399:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786747100/real 1786747100] req@ffff9b5f7c3afb80 x1873539644263936/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786747116 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 850.298058] Lustre: 16399:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 857.867552] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 862.194028] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 869.348176] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 869.359975] Lustre: Skipped 4 previous similar messages [ 870.323742] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 870.382257] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 870.833059] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 870.839157] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:233 to 0x280000400:257) [ 874.369993] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 876.000599] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 876.035825] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 876.084100] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 876.085034] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 895.256690] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 910.944824] Lustre: 38915:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 931.823595] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 935.052448] Lustre: 40050:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 955.284538] Lustre: Failing over lustre-MDT0000 [ 955.533357] Lustre: server umount lustre-MDT0000 complete [ 957.920405] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 957.927873] LustreError: Skipped 1 previous similar message [ 957.928417] 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 [ 957.932756] LustreError: 21163:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 957.932766] LustreError: 21163:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 10 previous similar messages [ 958.001856] Lustre: Skipped 5 previous similar messages [ 958.921079] Lustre: Failing over lustre-MDT0001 [ 958.921301] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747224 with bad export cookie 12884375591240646 [ 958.922820] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 958.967179] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 959.146631] Lustre: server umount lustre-MDT0001 complete [ 963.023394] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 971.392738] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 978.399229] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786747228/real 1786747228] req@ffff9b5e4aadb800 x1873539644410880/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786747244 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 978.427414] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 982.212250] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 982.260550] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 983.391111] LustreError: 41804:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 983.407333] LustreError: 41804:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9b5e4aba1500 x1873539644411264/t0(0) o250->MGC192.168.206.107@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786747249 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 983.442287] LustreError: 41804:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 983.583742] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5f818fa300 x1873539644412800/t0(0) o250->MGC192.168.206.107@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 [ 983.971659] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 983.976382] Lustre: Skipped 3 previous similar messages [ 984.021967] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 988.060887] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 996.801213] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 996.829390] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 997.189420] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 997.192380] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 998.177247] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 998.182276] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 998.194746] Lustre: Skipped 4 previous similar messages [ 998.240310] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 998.279176] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 998.280770] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 1002.076213] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1022.458606] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 1038.011845] Lustre: 44765:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1057.922804] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1061.135200] Lustre: 45901:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1081.031407] Lustre: Failing over lustre-MDT0000 [ 1081.303106] Lustre: server umount lustre-MDT0000 complete [ 1084.551190] LustreError: 19226:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747350 with bad export cookie 12884375591268436 [ 1084.561172] Lustre: Failing over lustre-MDT0001 [ 1084.562865] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1084.812538] Lustre: server umount lustre-MDT0001 complete [ 1089.184944] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1094.913465] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1101.284321] 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 [ 1101.304658] Lustre: Skipped 5 previous similar messages [ 1103.660803] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1103.692796] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1109.536788] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc64576459ce2 [ 1109.872684] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1110.495103] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786747360/real 1786747360] req@ffff9b5e420ad500 x1873539644558336/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786747376 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1110.523595] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 18 previous similar messages [ 1113.872223] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1121.243676] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1121.295412] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1121.496139] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1121.506576] LustreError: Skipped 1 previous similar message [ 1121.610259] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:361 to 0x2c0000400:385) [ 1121.614334] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1125.497526] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1126.886706] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1126.908901] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1126.944831] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1126.945779] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 1139.471589] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 18:43:23 (1786747403) [ 1151.484435] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 1167.573893] Lustre: 50614:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1187.049536] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1211.146290] Lustre: Failing over lustre-MDT0000 [ 1211.391430] Lustre: server umount lustre-MDT0000 complete [ 1213.933644] LustreError: 47474:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1213.953028] LustreError: 47474:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 20 previous similar messages [ 1214.232566] Lustre: Failing over lustre-MDT0001 [ 1214.233551] LustreError: 25725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747479 with bad export cookie 12884375591296226 [ 1214.239800] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1214.250931] LustreError: 25725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 1214.507905] Lustre: server umount lustre-MDT0001 complete [ 1219.114562] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1226.774937] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1233.420968] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1241.214537] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1249.479415] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1249.494136] Lustre: lustre-MDT0000: reset Object Index mappings [ 1260.376379] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1260.384791] Lustre: Skipped 3 previous similar messages [ 1260.410811] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1264.082550] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1270.992253] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1271.012499] Lustre: lustre-MDT0001: reset Object Index mappings [ 1271.312788] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:426 to 0x2c0000400:449) [ 1271.312838] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:425 to 0x280000400:449) [ 1274.678367] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1276.391109] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1276.434115] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1276.434223] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1276.441186] Lustre: Skipped 10 previous similar messages [ 1276.461996] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1276.462827] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 1284.039978] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 18:45:47 (1786747547) [ 1304.059952] Lustre: Failing over lustre-MDT0000 [ 1304.344804] Lustre: server umount lustre-MDT0000 complete [ 1307.646286] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747573 with bad export cookie 12884375591324016 [ 1307.648277] Lustre: Failing over lustre-MDT0001 [ 1307.650260] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1307.659917] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1307.956877] Lustre: server umount lustre-MDT0001 complete [ 1312.696480] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1321.326799] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1328.109772] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1336.154304] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1345.155852] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1345.171344] Lustre: lustre-MDT0000: reset Object Index mappings [ 1353.186986] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc64576467445 [ 1353.569931] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1357.162512] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1363.505756] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1363.525090] Lustre: lustre-MDT0001: reset Object Index mappings [ 1363.858430] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1363.859256] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:489 to 0x2c0000400:513) [ 1367.044422] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1369.062626] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1369.103579] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1369.145608] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1369.147498] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:521 to 0x280000401:545) [ 1372.713209] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32004: rc = 0 [ 1373.836055] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32034 with flags 0x52: rc = 0 [ 1390.628864] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 18:47:34 (1786747654) [ 1411.772953] Lustre: Failing over lustre-MDT0000 [ 1412.007290] Lustre: server umount lustre-MDT0000 complete [ 1412.066324] 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 [ 1412.083481] Lustre: Skipped 15 previous similar messages [ 1415.714400] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747681 with bad export cookie 12884375591351365 [ 1415.716881] Lustre: Failing over lustre-MDT0001 [ 1415.719701] LustreError: 21182:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1416.052692] Lustre: server umount lustre-MDT0001 complete [ 1421.114981] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1429.200677] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1432.479432] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786747682/real 1786747682] req@ffff9b5f6de28e00 x1873539644936448/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786747698 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1432.504560] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 35 previous similar messages [ 1435.603386] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1443.631407] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1452.617523] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1452.635277] Lustre: lustre-MDT0000: reset Object Index mappings [ 1461.607142] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1465.869311] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1473.309491] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1473.326369] Lustre: lustre-MDT0001: reset Object Index mappings [ 1473.594155] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1473.599555] LustreError: Skipped 3 previous similar messages [ 1473.714736] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1473.720156] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1476.847028] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:585 to 0x2c0000401:609) [ 1476.853131] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 1477.848226] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1485.012578] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32042: rc = 0 [ 1488.222729] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32031 with flags 0x52: rc = 0 [ 1604.070739] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 18:51:07 (1786747867) [ 1637.901223] Lustre: Failing over lustre-MDT0000 [ 1638.091723] Lustre: server umount lustre-MDT0000 complete [ 1641.463959] LustreError: 31642:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786747907 with bad export cookie 12884375591378616 [ 1641.464948] Lustre: Failing over lustre-MDT0001 [ 1641.466971] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1641.466988] LustreError: Skipped 1 previous similar message [ 1641.480900] LustreError: 31642:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1641.868211] Lustre: server umount lustre-MDT0001 complete [ 1646.451418] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1654.472850] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1662.095803] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1671.464622] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1681.824424] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1681.845603] Lustre: lustre-MDT0000: reset Object Index mappings [ 1687.008039] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5f4fd62a00 x1873539645130112/t0(0) o250->MGC192.168.206.107@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 [ 1687.461817] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1691.022708] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1698.641053] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1699.025524] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:617 to 0x2c0000400:641) [ 1699.028947] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 1703.153397] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1704.418170] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1704.431817] Lustre: Skipped 1 previous similar message [ 1704.481075] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1704.497298] Lustre: Skipped 1 previous similar message [ 1704.535551] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 1704.535645] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 1710.687899] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32030: rc = 0 [ 1713.988514] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 1794.350778] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 18:54:18 (1786748058) [ 1808.163618] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1808.170417] Lustre: Skipped 1 previous similar message [ 1808.673499] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1808.676386] Lustre: Skipped 51 previous similar messages [ 1809.679535] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1809.681548] Lustre: Skipped 247 previous similar messages [ 1825.345107] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 18:54:48 (1786748088) [ 1829.891029] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 1829.894735] Lustre: Skipped 155 previous similar messages [ 1830.222814] LustreError: 40075:0:(osd_compat.c:736:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 264/1058966004 265/1192580140 [ 1841.166274] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 18:55:04 (1786748104) [ 1858.021624] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1859.047746] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1859.062347] Lustre: Skipped 3 previous similar messages [ 1863.021033] Lustre: server umount lustre-MDT0000 complete [ 1864.165136] LustreError: 69598:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1864.180316] LustreError: 69598:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 27 previous similar messages [ 1869.291033] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1869.297558] Lustre: Skipped 1 previous similar message [ 1871.328939] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1871.336558] Lustre: Skipped 1 previous similar message [ 1876.453757] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1876.457333] Lustre: Skipped 1 previous similar message [ 1881.055365] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1881.379086] Lustre: server umount lustre-MDT0001 complete [ 1891.115499] Lustre: server umount lustre-OST0000 complete [ 1909.215330] Lustre: lustre-OST0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1909.413879] Lustre: server umount lustre-OST0001 complete [ 1915.924911] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_hostid [ 1924.261991] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 1969.977412] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 1981.115726] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1981.342237] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1981.368947] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1981.467731] Lustre: lustre-MDT0000: new disk, initializing [ 1981.619623] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1981.628646] Lustre: Skipped 7 previous similar messages [ 1981.644444] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1985.515642] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1994.601783] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1994.648673] Lustre: 75758: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 [ 1994.657216] Lustre: 75758:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1994.680114] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1994.683075] Lustre: Skipped 1 previous similar message [ 1994.742703] Lustre: lustre-MDT0001: new disk, initializing [ 1994.810433] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1994.818274] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1998.433284] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2002.429326] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2007.534226] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2007.727651] Lustre: lustre-OST0000: new disk, initializing [ 2007.732230] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2007.738794] Lustre: 77389:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2009.192380] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2009.205660] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2009.268022] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2012.741789] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2022.074105] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2022.176436] Lustre: lustre-OST0001: new disk, initializing [ 2022.180817] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2022.185515] Lustre: 78261:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2023.425930] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2023.436872] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2023.492731] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2027.290374] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2035.587353] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2038.663855] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2058.704758] Lustre: Failing over lustre-MDT0000 [ 2058.951306] Lustre: server umount lustre-MDT0000 complete [ 2059.233207] 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 [ 2059.253438] Lustre: Skipped 16 previous similar messages [ 2062.013593] Lustre: Failing over lustre-MDT0001 [ 2062.014319] LustreError: 75751:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786748327 with bad export cookie 12884375591516852 [ 2062.019728] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2062.037952] LustreError: 75751:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 5 previous similar messages [ 2062.053826] LustreError: Skipped 1 previous similar message [ 2062.329522] Lustre: server umount lustre-MDT0001 complete [ 2067.005326] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2075.708390] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2080.744806] Lustre: 16399:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786748330/real 1786748330] req@ffff9b5f7c30dc00 x1873539645432192/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786748346 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2080.763819] Lustre: 16399:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 2083.069927] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2091.110777] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2101.444481] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2101.462075] Lustre: lustre-MDT0000: reset Object Index mappings [ 2101.466396] Lustre: Skipped 1 previous similar message [ 2106.407654] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc645764944c7 [ 2106.416745] Lustre: MGC192.168.206.107@tcp: Connection restored to 0@lo (at 0@lo) [ 2106.426890] Lustre: Skipped 20 previous similar messages [ 2106.763546] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2110.513940] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2117.988839] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2118.189119] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2118.196232] LustreError: Skipped 2 previous similar messages [ 2118.279911] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2118.281446] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 2121.823304] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2123.782770] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2123.811244] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2123.848307] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 2123.855904] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2129.558474] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/64002: rc = 0 [ 2129.558509] Lustre: *** cfs_fail_loc=190, val=3*** [ 2130.630348] Lustre: *** cfs_fail_loc=190, val=3*** [ 2130.636700] Lustre: Skipped 1 previous similar message [ 2131.717155] Lustre: *** cfs_fail_loc=190, val=3*** [ 2132.790065] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2134.751374] Lustre: *** cfs_fail_loc=190, val=3*** [ 2134.758184] Lustre: Skipped 2 previous similar messages [ 2138.911134] Lustre: *** cfs_fail_loc=191, val=3*** [ 2138.918385] Lustre: Skipped 2 previous similar messages [ 2144.412658] Lustre: Failing over lustre-MDT0000 [ 2144.859426] Lustre: server umount lustre-MDT0000 complete [ 2149.410031] Lustre: Failing over lustre-MDT0001 [ 2149.802105] Lustre: server umount lustre-MDT0001 complete [ 2160.282492] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2174.945700] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc64576494bc7 [ 2180.287758] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2189.234834] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2189.555610] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:97) [ 2189.561919] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2193.652335] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2194.973042] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2194.973475] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:97) [ 2199.523715] Lustre: Failing over lustre-MDT0000 [ 2199.822841] Lustre: server umount lustre-MDT0000 complete [ 2204.336423] Lustre: Failing over lustre-MDT0001 [ 2204.903657] Lustre: server umount lustre-MDT0001 complete [ 2215.568056] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2215.687943] Lustre: *** cfs_fail_loc=190, val=3*** [ 2215.689962] Lustre: Skipped 1 previous similar message [ 2233.771248] Lustre: *** cfs_fail_loc=190, val=3*** [ 2233.774035] Lustre: Skipped 5 previous similar messages [ 2236.300549] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2245.360759] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2245.814935] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:129) [ 2245.815417] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2250.334626] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2251.335402] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:129) [ 2251.337139] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2262.314239] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/122: rc = 0 [ 2262.322080] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2274.358039] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 19:02:17 (1786748537) [ 2301.409077] Lustre: Failing over lustre-MDT0000 [ 2303.708900] Lustre: server umount lustre-MDT0000 complete [ 2307.341822] Lustre: Failing over lustre-MDT0001 [ 2307.687561] Lustre: server umount lustre-MDT0001 complete [ 2313.639525] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2323.418815] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2331.749091] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2341.505065] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2352.844720] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2352.871477] Lustre: lustre-MDT0000: reset Object Index mappings [ 2352.878453] Lustre: Skipped 1 previous similar message [ 2383.470722] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2391.639383] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2392.076020] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 2392.089433] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 2396.259601] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2397.220551] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 2397.221848] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 2404.494941] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/64002: rc = 0 [ 2404.497260] Lustre: *** cfs_fail_loc=190, val=2*** [ 2404.515583] Lustre: Skipped 13 previous similar messages [ 2407.822389] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 2421.301482] Lustre: lustre-MDT0001: trigger partial OI scrub for RPC inconsistency, checking FID [0x240001b71:0x44:0x0]/55: rc = 0 [ 2421.311380] Lustre: Skipped 1 previous similar message [ 2434.918694] Lustre: Failing over lustre-MDT0000 [ 2435.385245] Lustre: server umount lustre-MDT0000 complete [ 2440.019518] Lustre: Failing over lustre-MDT0001 [ 2440.283950] Lustre: server umount lustre-MDT0001 complete [ 2449.403283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2465.030801] LustreError: 77383:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2465.052315] LustreError: 77383:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 60 previous similar messages [ 2470.164654] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2470.625754] Lustre: *** cfs_fail_loc=190, val=3*** [ 2470.631082] Lustre: Skipped 30 previous similar messages [ 2480.264885] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2480.789447] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 2480.810498] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 2485.881437] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:225) [ 2485.882637] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 2487.118080] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2509.047263] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 19:06:12 (1786748772) [ 2525.617736] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 2544.712361] Lustre: 96461:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2567.508622] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2571.007840] Lustre: 97596:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2608.320651] Lustre: Failing over lustre-MDT0000 [ 2610.565181] Lustre: server umount lustre-MDT0000 complete [ 2614.167397] LustreError: 77388:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786748879 with bad export cookie 12884375591582596 [ 2614.170186] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2614.179121] LustreError: 77388:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 9 previous similar messages [ 2614.196032] LustreError: Skipped 4 previous similar messages [ 2614.207147] Lustre: Failing over lustre-MDT0001 [ 2614.574635] Lustre: server umount lustre-MDT0001 complete [ 2619.536305] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2629.335519] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2638.544532] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2650.723327] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2663.747212] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2663.792806] Lustre: lustre-MDT0000: reset Object Index mappings [ 2663.801862] Lustre: Skipped 1 previous similar message [ 2683.359455] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5f70e39c00 x1873539645829248/t0(0) o250->MGC192.168.206.107@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 [ 2683.766827] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2683.770020] Lustre: Skipped 13 previous similar messages [ 2683.807412] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2683.820073] Lustre: Skipped 4 previous similar messages [ 2688.976886] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2702.155359] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2702.573187] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:265 to 0x2c0000400:289) [ 2702.596638] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 2704.610369] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2704.644353] Lustre: Skipped 4 previous similar messages [ 2704.686668] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2704.704530] Lustre: Skipped 4 previous similar messages [ 2704.808930] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 2704.811429] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 2709.393662] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2720.578553] Lustre: *** cfs_fail_loc=190, val=3*** [ 2720.578950] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32039: rc = 0 [ 2720.586781] Lustre: Skipped 13 previous similar messages [ 2723.932818] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 2747.824367] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 19:10:10 (1786749010) [ 2799.120657] Lustre: Failing over lustre-MDT0000 [ 2799.532594] Lustre: server umount lustre-MDT0000 complete [ 2800.099097] 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 [ 2800.131910] Lustre: Skipped 36 previous similar messages [ 2803.553078] Lustre: Failing over lustre-MDT0001 [ 2803.840598] Lustre: server umount lustre-MDT0001 complete [ 2809.705204] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2820.511106] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786749070/real 1786749070] req@ffff9b5e48e35880 x1873539645970944/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786749086 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2820.541186] Lustre: 16397:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 54 previous similar messages [ 2820.683770] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2830.739254] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2841.914912] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2854.617642] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2878.784505] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2888.281187] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2888.605245] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2888.612673] LustreError: Skipped 8 previous similar messages [ 2888.753143] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:329 to 0x2c0000400:353) [ 2888.756724] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 2889.768142] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2889.773950] Lustre: Skipped 31 previous similar messages [ 2889.821804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 2889.822463] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 2893.110833] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2931.921680] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 19:13:15 (1786749195) [ 2945.358906] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 2964.055791] Lustre: 109068:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2993.509671] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3121.731330] Lustre: Failing over lustre-MDT0000 [ 3122.320655] Lustre: server umount lustre-MDT0000 complete [ 3124.209560] LustreError: 77382:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3124.218585] LustreError: 77382:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 34 previous similar messages [ 3125.451183] Lustre: Failing over lustre-MDT0001 [ 3126.076702] Lustre: server umount lustre-MDT0001 complete [ 3131.070713] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3143.282977] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3155.529567] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3169.006173] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3187.207041] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3187.251205] Lustre: lustre-MDT0000: reset Object Index mappings [ 3187.267091] Lustre: Skipped 3 previous similar messages [ 3201.271879] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3211.603982] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3212.103674] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 3212.116790] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:393 to 0x2c0000400:417) [ 3215.166229] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3215.169200] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 3216.995774] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3279.298483] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 19:19:02 (1786749542) [ 3295.062419] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 3314.894331] Lustre: 117044:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3314.908744] Lustre: 117044:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 3339.452215] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3516.887929] Lustre: Failing over lustre-MDT0000 [ 3517.113105] Lustre: server umount lustre-MDT0000 complete [ 3517.408086] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3517.419056] LustreError: Skipped 1 previous similar message [ 3517.424794] 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 [ 3517.433857] Lustre: Skipped 9 previous similar messages [ 3520.744113] Lustre: Failing over lustre-MDT0001 [ 3520.756844] LustreError: 75749:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786749786 with bad export cookie 12884375591932589 [ 3520.768471] LustreError: 75749:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 3520.771904] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3520.804985] LustreError: Skipped 2 previous similar messages [ 3521.097671] Lustre: server umount lustre-MDT0001 complete [ 3526.218441] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3536.119058] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3537.377192] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786749787/real 1786749787] req@ffff9b5e4fc4ad80 x1873539646440192/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786749803 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3537.407965] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 27 previous similar messages [ 3547.070787] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3558.479768] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3571.765337] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3591.088670] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3591.093447] Lustre: Skipped 5 previous similar messages [ 3591.130914] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3591.144814] Lustre: Skipped 2 previous similar messages [ 3595.313538] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3604.178760] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3604.565362] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 3604.572610] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 3607.593512] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3607.599813] Lustre: Skipped 9 previous similar messages [ 3607.609607] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3607.616146] Lustre: Skipped 2 previous similar messages [ 3607.624812] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3607.638223] Lustre: Skipped 2 previous similar messages [ 3607.708229] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 3607.711327] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 3608.538584] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3617.038042] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32030: rc = 0 [ 3617.040139] Lustre: *** cfs_fail_loc=190, val=1*** [ 3617.060889] Lustre: Skipped 44 previous similar messages [ 3620.317618] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 3627.773736] Lustre: Failing over lustre-MDT0000 [ 3628.297784] Lustre: server umount lustre-MDT0000 complete [ 3631.794393] Lustre: Failing over lustre-MDT0001 [ 3632.107701] Lustre: server umount lustre-MDT0001 complete [ 3639.363667] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3641.503156] LustreError: 122988:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 3641.515337] LustreError: 122988:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9b5f7f6f2a00 x1873539646476288/t0(0) o250->MGC192.168.206.107@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786749907 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_02.0' uid:0 gid:0 projid:4294967295 [ 3641.545237] LustreError: 122988:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 3642.279112] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc645765a0718 [ 3646.922948] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3655.378721] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3655.824945] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 3655.827863] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 3660.281186] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3660.882824] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:513) [ 3660.883076] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 3667.128726] Lustre: Failing over lustre-MDT0000 [ 3667.406807] Lustre: server umount lustre-MDT0000 complete [ 3671.472343] Lustre: Failing over lustre-MDT0001 [ 3671.879449] Lustre: server umount lustre-MDT0001 complete [ 3680.352385] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3680.433097] Lustre: *** cfs_fail_loc=190, val=1*** [ 3680.437900] Lustre: Skipped 26 previous similar messages [ 3681.503196] LustreError: 124952:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 3681.512734] LustreError: 124952:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9b5f68c1d500 x1873539646502784/t0(0) o250->MGC192.168.206.107@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786749947 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 3681.541194] LustreError: 124952:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 3682.275886] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc645765a0d77 [ 3688.140091] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3697.073753] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3697.432637] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 3697.437482] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 3701.703436] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3702.823400] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:545) [ 3702.825173] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:545) [ 3717.189991] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 19:26:20 (1786749980) [ 3732.588833] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 3752.230876] Lustre: 128063:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3752.241577] Lustre: 128063:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 3774.866662] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3808.174738] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 19:27:51 (1786750071) [ 3813.585462] Lustre: *** cfs_fail_loc=195, val=0*** [ 3814.417275] Lustre: *** cfs_fail_loc=195, val=0*** [ 3814.423581] Lustre: Skipped 31 previous similar messages [ 3819.986359] Lustre: Failing over lustre-OST0000 [ 3820.239336] Lustre: server umount lustre-OST0000 complete [ 3820.521865] LustreError: 110226:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3820.537733] LustreError: 110226:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 34 previous similar messages [ 3830.736897] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3838.273812] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4032.180488] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 19:31:35 (1786750295) [ 4036.404911] Lustre: *** cfs_fail_loc=196, val=0*** [ 4036.420647] Lustre: Skipped 31 previous similar messages [ 4041.844461] Lustre: Failing over lustre-OST0000 [ 4041.935912] Lustre: server umount lustre-OST0000 complete [ 4050.573321] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4056.876879] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4250.258964] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 19:35:13 (1786750513) [ 4256.808397] Lustre: *** cfs_fail_loc=196, val=0*** [ 4256.810393] Lustre: Skipped 63 previous similar messages [ 4261.199614] Lustre: *** cfs_fail_loc=196, val=0*** [ 4261.201448] Lustre: Skipped 287 previous similar messages [ 4269.318091] Lustre: *** cfs_fail_loc=196, val=0*** [ 4269.319782] Lustre: Skipped 511 previous similar messages [ 4279.733654] Lustre: Failing over lustre-OST0000 [ 4279.843273] Lustre: server umount lustre-OST0000 complete [ 4281.336276] 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 [ 4281.364206] Lustre: Skipped 21 previous similar messages [ 4290.494870] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4290.716455] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4290.726460] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4290.736397] Lustre: Skipped 4 previous similar messages [ 4292.578304] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4292.595104] Lustre: Skipped 4 previous similar messages [ 4292.610785] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4292.613611] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4292.618320] Lustre: Skipped 4 previous similar messages [ 4292.623595] Lustre: Skipped 20 previous similar messages [ 4296.358885] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4308.026711] Lustre: server umount lustre-MDT0000 complete [ 4311.558860] LustreError: 87975:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786750577 with bad export cookie 12884375592635767 [ 4311.560705] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4311.569393] LustreError: 87975:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 5 previous similar messages [ 4311.576329] LustreError: Skipped 2 previous similar messages [ 4311.851676] Lustre: server umount lustre-MDT0001 complete [ 4326.046853] Lustre: server umount lustre-OST0000 complete [ 4341.154822] Lustre: server umount lustre-OST0001 complete [ 4353.312732] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 19:36:56 (1786750616) [ 4368.960756] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_hostid [ 4378.540803] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 4425.632704] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 4436.844802] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4437.062926] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4437.084294] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4437.156966] Lustre: lustre-MDT0000: new disk, initializing [ 4437.225919] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4437.235135] Lustre: Skipped 7 previous similar messages [ 4437.271770] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4441.485580] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4452.451337] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4452.520589] Lustre: 139377: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 [ 4452.528697] Lustre: 139377:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4452.547373] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4452.557148] Lustre: Skipped 1 previous similar message [ 4452.602352] Lustre: lustre-MDT0001: new disk, initializing [ 4452.661961] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4452.671926] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4457.264829] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4462.449758] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4469.786976] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4470.068405] Lustre: lustre-OST0000: new disk, initializing [ 4470.075368] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4470.086381] Lustre: 141009:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4471.274547] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4471.297490] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4471.457728] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4477.565576] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4490.806487] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4490.946731] Lustre: lustre-OST0001: new disk, initializing [ 4490.951694] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4490.958488] Lustre: 141878:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4492.936524] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4492.947268] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4493.047385] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4498.346633] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4508.247599] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4511.856696] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4531.743020] Lustre: Failing over lustre-MDT0000 [ 4531.994304] Lustre: server umount lustre-MDT0000 complete [ 4534.243194] LustreError: 142664:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4534.260188] LustreError: 142664:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 19 previous similar messages [ 4535.929058] Lustre: Failing over lustre-MDT0001 [ 4536.244986] Lustre: server umount lustre-MDT0001 complete [ 4541.923736] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4552.043351] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4555.681546] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786750805/real 1786750805] req@ffff9b5f7085f100 x1873539647028352/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786750821 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4555.720125] Lustre: 16396:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 4560.250750] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4571.249855] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4582.790578] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4582.815203] Lustre: lustre-MDT0000: reset Object Index mappings [ 4582.817773] Lustre: Skipped 3 previous similar messages [ 4605.924962] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5f4fd71880 x1873539647032064/t0(0) o250->MGC192.168.206.107@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 [ 4611.415982] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4620.872093] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4621.199591] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 4621.206342] LustreError: Skipped 7 previous similar messages [ 4621.368526] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 4621.368781] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 4624.418810] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 4624.418848] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 4627.088731] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4680.535845] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 19:42:24 (1786750944) [ 4693.948451] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 4732.865830] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4761.117916] Lustre: Failing over lustre-MDT0000 [ 4761.124992] Lustre: *** cfs_fail_loc=199, val=0*** [ 4761.130930] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 4761.137283] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 4761.148492] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 4761.162831] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 4761.170644] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 4761.176847] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 4761.184294] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 4761.192772] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 4761.207372] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 4761.220581] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 4761.231430] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 4761.237468] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 4761.250662] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 4761.266123] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 4761.282643] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 4761.312864] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 4761.327210] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 4761.348831] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 4761.360311] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 4761.374548] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 4761.390171] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 4761.402267] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 4761.412517] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 4761.424470] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 4761.436935] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 4761.451676] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 4761.464808] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 4761.472311] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 4761.480891] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 4761.489150] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 4761.498313] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 4761.507876] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 4761.515651] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 4761.521952] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 4761.528313] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 4761.534069] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 4761.540427] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 4761.546430] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 4761.553457] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 4761.559524] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 4761.565962] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 4761.572623] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 4761.579708] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 4761.589334] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 4761.599404] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 4761.606928] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 4761.615736] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 4761.622763] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 4761.630178] Lustre: *** cfs_fail_loc=199, val=0*** [ 4761.633252] Lustre: Skipped 47 previous similar messages [ 4761.636457] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 4761.642522] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 4761.655100] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 4761.665473] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 4761.676367] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 4761.683551] Lustre: 151624:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 4761.933463] Lustre: server umount lustre-MDT0000 complete [ 4765.810872] Lustre: Failing over lustre-MDT0001 [ 4765.823063] Lustre: *** cfs_fail_loc=199, val=0*** [ 4765.826716] Lustre: Skipped 5 previous similar messages [ 4765.830308] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 4765.840080] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 4765.848070] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 4765.856823] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 4765.863231] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 4765.870085] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 4765.880593] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 4765.887503] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 4765.895150] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 4765.902566] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 4765.909040] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 4765.916323] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 4765.923570] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 4765.930809] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 4765.936884] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 4765.943993] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 4765.950742] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 4765.957870] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 4765.964041] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 4765.969987] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 4765.976080] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 4765.983324] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 4765.988591] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 4765.994558] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 4765.999522] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 4766.006076] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 4766.011202] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 4766.016441] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 4766.021202] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 4766.026200] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 4766.033176] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 4766.038939] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 4766.045217] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 4766.052084] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 4766.058126] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 4766.066627] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 4766.078519] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 4766.095111] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 4766.109031] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 4766.116479] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 4766.122410] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 4766.135558] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 4766.147509] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 4766.156578] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 4766.164697] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 4766.172877] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 4766.181303] Lustre: 151825:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 4766.660951] Lustre: server umount lustre-MDT0001 complete [ 4776.952260] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4777.096289] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 4777.112624] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 4777.125894] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 4777.144923] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 4777.167282] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 4777.181543] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 4777.198262] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 4777.217749] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 4777.234234] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 4777.243813] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 4777.258395] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 4777.270326] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 4777.290285] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 4777.299175] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 4777.308878] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 4777.324411] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 4777.353411] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 4777.367486] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 4777.373642] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 4777.380671] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 4777.394356] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 4777.406691] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 4777.416857] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 4777.427338] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 4777.438612] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 4777.446279] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 4777.456766] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 4777.463948] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 4777.471473] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 4777.484925] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 4777.500178] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 4777.512551] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 4777.519673] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 4777.530156] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 4777.542183] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 4777.562923] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 4777.580217] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 4777.610989] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 4777.630526] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 4777.643667] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 4777.664393] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 4777.685178] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 4777.705482] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 4777.726403] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 4777.744486] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 4777.759657] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 4777.780635] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 4777.794644] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 4777.805889] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 4777.823984] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 4777.833936] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 4777.844326] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 4777.856872] Lustre: 152321:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 4796.002993] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4805.571492] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4805.668197] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 4805.687688] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 4805.702111] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 4805.713238] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 4805.723706] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 4805.740297] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 4805.765813] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 4805.789221] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 4805.804778] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 4805.836974] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 4805.862259] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 4805.872896] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 4805.886607] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 4805.898395] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 4805.913666] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 4805.926285] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 4805.954872] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 4805.977174] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 4805.997906] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 4806.022257] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 4806.041597] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 4806.066196] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 4806.086936] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 4806.104475] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 4806.120182] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 4806.131712] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 4806.146622] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 4806.168430] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 4806.188284] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 4806.208414] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 4806.227471] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 4806.242966] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 4806.260702] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 4806.273835] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 4806.291239] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 4806.318218] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 4806.335713] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 4806.356105] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 4806.362920] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 4806.380083] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 4806.398342] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 4806.408811] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 4806.434993] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 4806.450769] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 4806.468587] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 4806.478581] Lustre: 153068:0:(osd_scrub.c:1864:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 4806.793410] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 4806.793764] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 4811.377447] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4811.800933] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 4811.805039] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 4822.065623] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 19:44:45 (1786751085) [ 4823.121464] Lustre: *** cfs_fail_loc=19d, val=0*** [ 4823.128593] Lustre: Skipped 123 previous similar messages [ 4825.175301] Lustre: Failing over lustre-MDT0000 [ 4825.397601] Lustre: server umount lustre-MDT0000 complete [ 4840.797243] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4845.212163] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4846.149198] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 4846.154537] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 4848.557694] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 19:45:12 (1786751112) [ 4849.379172] Lustre: *** cfs_fail_loc=19e, val=0*** [ 4851.085238] Lustre: Failing over lustre-MDT0000 [ 4851.171812] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4851.183604] Lustre: Skipped 3 previous similar messages [ 4851.469963] Lustre: server umount lustre-MDT0000 complete [ 4867.444574] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4872.840540] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4873.232065] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 4873.233623] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:193) [ 4876.295412] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 19:45:39 (1786751139) [ 4898.314986] Lustre: Failing over lustre-MDT0000 [ 4898.697141] Lustre: server umount lustre-MDT0000 complete [ 4898.784058] 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 [ 4898.791907] Lustre: Skipped 26 previous similar messages [ 4901.767455] Lustre: Failing over lustre-MDT0001 [ 4902.095192] Lustre: server umount lustre-MDT0001 complete [ 4910.504984] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4911.714495] LustreError: 157102:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 4911.730705] LustreError: 157102:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9b5e425a4e00 x1873539647350016/t0(0) o250->MGC192.168.206.107@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1786751177 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 4911.749720] LustreError: 157102:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 4912.032115] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5f76267480 x1873539647351424/t0(0) o250->MGC192.168.206.107@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 [ 4912.541255] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4912.549107] Lustre: Skipped 4 previous similar messages [ 4916.618545] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4918.758989] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4918.765437] Lustre: Skipped 19 previous similar messages [ 4924.506764] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4924.929202] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 4924.929718] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 4929.726091] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4930.026157] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4930.033412] Lustre: Skipped 4 previous similar messages [ 4930.074177] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4930.087733] Lustre: Skipped 4 previous similar messages [ 4930.146992] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 4930.150059] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 4936.088574] Lustre: Failing over lustre-MDT0000 [ 4938.335960] Lustre: server umount lustre-MDT0000 complete [ 4941.413827] LustreError: 139371:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786751207 with bad export cookie 12884375592830654 [ 4941.415333] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4941.416268] Lustre: Failing over lustre-MDT0001 [ 4941.424030] LustreError: 139371:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 4941.442608] LustreError: Skipped 5 previous similar messages [ 4941.742334] Lustre: server umount lustre-MDT0001 complete [ 4949.039936] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4949.067670] Lustre: lustre-MDT0000: reset Object Index mappings [ 4949.071151] Lustre: Skipped 1 previous similar message [ 4951.521122] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x2dc645765d0d32 [ 4955.985366] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4963.006909] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4963.564868] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 4963.570469] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 4967.555856] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4969.029587] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:289) [ 4969.029739] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 4979.379117] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 19:47:22 (1786751242) [ 4989.409367] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4989.417700] Lustre: Skipped 3 previous similar messages [ 4994.531357] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4994.564197] Lustre: Skipped 3 previous similar messages [ 4995.655364] Lustre: server umount lustre-MDT0000 complete [ 5000.502743] Lustre: server umount lustre-MDT0001 complete [ 5015.352376] Lustre: server umount lustre-OST0000 complete [ 5029.172260] Lustre: server umount lustre-OST0001 complete [ 5036.057869] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5043.926374] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5059.489505] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5064.607399] LustreError: 161832:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.107@tcp: failed processing log, type 4: rc = -110 [ 5090.335217] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5090.339408] Lustre: Skipped 13 previous similar messages [ 5097.164346] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5103.389992] Lustre: Failing over lustre-OST0000 [ 5103.652271] Lustre: server umount lustre-OST0000 complete [ 5110.735748] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5121.039822] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5136.671348] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5141.792441] LustreError: 163357:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.107@tcp: failed processing log, type 4: rc = -110 [ 5174.898371] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5185.800553] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 19:50:49 (1786751449) [ 5204.742588] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 5217.564807] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5217.900508] LustreError: 163382:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5217.928443] LustreError: 163382:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 76 previous similar messages [ 5218.143539] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5224.625084] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5235.883092] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5236.274970] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5241.218622] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5244.342675] Lustre: 166265:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5244.353993] Lustre: 166265:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 2 previous similar messages [ 5261.733834] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5266.925038] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:321) [ 5266.943654] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:257) [ 5269.393648] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5277.621186] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5283.835804] Lustre: *** cfs_fail_loc=193, val=0*** [ 5285.630618] Lustre: Failing over lustre-MDT0000 [ 5285.846471] Lustre: server umount lustre-MDT0000 complete [ 5294.483701] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5294.733038] Lustre: *** cfs_fail_loc=193, val=0*** [ 5294.734718] Lustre: Skipped 1 previous similar message [ 5300.050646] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5300.290596] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:353) [ 5300.291725] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5300.322500] Lustre: *** cfs_fail_loc=193, val=0*** [ 5300.324264] Lustre: Skipped 3 previous similar messages [ 5304.001068] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5304.001140] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5304.003027] Lustre: Skipped 35 previous similar messages [ 5310.970443] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5310.977092] Lustre: Skipped 3 previous similar messages [ 5317.862775] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 19:53:01 (1786751581) [ 5320.305338] Lustre: Failing over lustre-MDT0000 [ 5320.696466] Lustre: server umount lustre-MDT0000 complete [ 5323.757228] Lustre: Failing over lustre-MDT0001 [ 5324.072919] Lustre: server umount lustre-MDT0001 complete [ 5326.637054] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5332.834120] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5333.919984] LustreError: 16395:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b5e4c800000 x1873539647544960/t0(0) o250->MGC192.168.206.107@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 [ 5334.232666] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000400:0x1:0x0]/41 with flags 0x4a: rc = 0 [ 5334.240545] Lustre: 170043:0:(lod_sub_object.c:941:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't open llog [0x200000400:0x1:0x0]: rc = -115 [ 5334.249929] LustreError: 170043:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osd: get update log duration 0, retries 0, failed: rc = -115 [ 5338.408907] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5341.663427] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786751591/real 1786751591] req@ffff9b5f4600c000 x1873539647544320/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786751607 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5341.686499] Lustre: 16398:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 39 previous similar messages [ 5345.833345] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5346.033600] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5346.044432] LustreError: Skipped 9 previous similar messages [ 5349.899895] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5351.679138] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000401:0x1:0x0]/40 with flags 0x4a: rc = 0 [ 5351.726119] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:385) [ 5351.731941] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5352.758408] LustreError: 170769:0:(update_trans.c:1080:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5352.835401] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 5352.837757] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:289) [ 5354.841624] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5361.319487] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 19:53:44 (1786751624) [ 5366.766692] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5371.739591] Lustre: server umount lustre-MDT0000 complete [ 5375.558706] Lustre: server umount lustre-MDT0001 complete [ 5389.199208] Lustre: server umount lustre-OST0000 complete [ 5393.233973] Lustre: server umount lustre-OST0001 complete [ 5399.628308] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5411.516237] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5416.317657] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5421.265684] Lustre: Failing over lustre-MDT0000 [ 5421.276647] LustreError: 173159:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5421.284366] LustreError: 173159:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5421.294056] LustreError: 173159:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 10, retries 0, failed: rc = -5 [ 5421.536489] Lustre: server umount lustre-MDT0000 complete [ 5427.691174] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5439.971736] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5444.679525] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5453.051688] Lustre: DEBUG MARKER: === sanity-scrub: start setup 19:55:16 (1786751716) === [ 5455.101815] LustreError: 174796:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5455.115262] LustreError: 174796:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5455.121443] LustreError: 174796:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 14, retries 0, failed: rc = -5 [ 5455.375950] Lustre: server umount lustre-MDT0000 complete [ 5485.274974] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_hostid [ 5492.327677] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 5539.899892] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing load_modules_local [ 5554.181451] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5554.426334] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5554.461592] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5554.574157] Lustre: lustre-MDT0000: new disk, initializing [ 5554.710730] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5558.976981] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5572.060766] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5572.245338] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5572.257258] Lustre: Skipped 1 previous similar message [ 5572.344775] Lustre: lustre-MDT0001: new disk, initializing [ 5572.427336] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5572.438393] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5576.661262] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5581.864683] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5591.619979] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5591.841289] Lustre: lustre-OST0000: new disk, initializing [ 5591.844900] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5591.849869] Lustre: 182097:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5593.684641] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5593.698788] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5593.781365] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5597.900387] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5612.035971] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5612.264762] Lustre: lustre-OST0001: new disk, initializing [ 5612.269728] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5612.275959] Lustre: 183123:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5614.389055] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5614.401829] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5619.554878] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5619.696270] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5628.698584] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5632.850706] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5638.564866] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 19:58:21 (1786751901) === [ 5640.207812] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 5398 sec ========= 19:58:23 (1786751903) [ 5641.873732] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 19:58:25 (1786751905) === [ 5645.339054] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 19:58:28 (1786751908) === [ 5649.377738] 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 [ 5649.395174] Lustre: Skipped 27 previous similar messages [ 5649.400379] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5649.404715] Lustre: Skipped 3 previous similar messages [ 5655.411864] Lustre: server umount lustre-MDT0000 complete [ 5663.939174] LustreError: 180148:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786751929 with bad export cookie 12884375592858836 [ 5663.943768] LustreError: MGC192.168.206.107@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5663.951530] LustreError: 180148:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 5663.985073] LustreError: Skipped 4 previous similar messages [ 5664.432394] Lustre: server umount lustre-MDT0001 complete [ 5682.814508] Lustre: server umount lustre-OST0000 complete [ 5692.749533] Lustre: server umount lustre-OST0001 complete [ 5711.977672] Lustre: DEBUG MARKER: oleg607-server.virtnet: executing unload_modules_local [ 5715.548612] Key type lgssc unregistered [ 5715.956681] LNet: 186539:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5715.963336] LNetError: 186539:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5715.991557] LNet: Removed LNI 192.168.206.107@tcp [ 5717.032164] Key type .llcrypt unregistered [ 5717.037359] Key type ._llcrypt unregistered