[ 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 530663808 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, 524584K 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.001123] APIC: Switch to symmetric I/O mode setup [ 0.002383] x2apic enabled [ 0.003005] Switched APIC routing to physical x2apic. [ 0.005008] kvm-guest: setup PV IPIs [ 0.006901] ..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.007038] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008009] pid_max: default: 32768 minimum: 301 [ 0.009142] LSM: Security Framework initializing [ 0.010039] Yama: becoming mindful. [ 0.011051] SELinux: Initializing. [ 0.012070] *** VALIDATE selinux *** [ 0.021134] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027788] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028235] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029112] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031102] *** VALIDATE tmpfs *** [ 0.033103] *** VALIDATE proc *** [ 0.034209] *** VALIDATE cgroup *** [ 0.035006] *** VALIDATE cgroup2 *** [ 0.036265] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037121] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038005] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040024] Spectre V2 : User space: Vulnerable [ 0.041006] Speculative Store Bypass: Vulnerable [ 0.044673] debug: unmapping init [mem 0xffffffff90e59000-0xffffffff90e60fff] [ 0.047174] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048709] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049014] ... version: 2 [ 0.049894] ... bit width: 48 [ 0.050007] ... generic registers: 4 [ 0.051008] ... value mask: 0000ffffffffffff [ 0.052013] ... max period: 00007fffffffffff [ 0.053011] ... fixed-purpose events: 3 [ 0.054008] ... event mask: 000000070000000f [ 0.055319] rcu: Hierarchical SRCU implementation. [ 0.057667] smp: Bringing up secondary CPUs ... [ 0.058660] x86: Booting SMP configuration: [ 0.059018] .... node #0, CPUs: #1 #2 #3 [ 0.071356] smp: Brought up 1 node, 4 CPUs [ 0.073014] smpboot: Max logical packages: 1 [ 0.074012] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.114058] node 0 deferred pages initialised in 38ms [ 0.117704] devtmpfs: initialized [ 0.118432] x86/mm: Memory block size: 128MB [ 0.122335] gcov: version magic: 0x41383552 [ 0.124099] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.125057] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.126223] pinctrl core: initialized pinctrl subsystem [ 0.127115] [ 0.127613] ************************************************************* [ 0.128009] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.129008] ** ** [ 0.130008] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.131008] ** ** [ 0.132010] ** This means that this kernel is built to expose internal ** [ 0.133017] ** IOMMU data structures, which may compromise security on ** [ 0.134028] ** your system. ** [ 0.135024] ** ** [ 0.136020] ** If you see this message and you are not debugging the ** [ 0.137017] ** kernel, report this immediately to your vendor! ** [ 0.138010] ** ** [ 0.139018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.140023] ************************************************************* [ 0.142140] NET: Registered protocol family 16 [ 0.143578] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.144055] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.145062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.146557] cpuidle: using governor menu [ 0.148887] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.152684] PCI: Using configuration type 1 for base access [ 0.155151] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.166220] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.167017] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.169036] cryptd: max_cpu_qlen set to 1000 [ 0.172038] ACPI: Added _OSI(Module Device) [ 0.174020] ACPI: Added _OSI(Processor Device) [ 0.176014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.179017] ACPI: Added _OSI(Processor Aggregator Device) [ 0.186943] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.194681] ACPI: Interpreter enabled [ 0.195053] ACPI: PM: (supports S0 S3 S4 S5) [ 0.196009] ACPI: Using IOAPIC for interrupt routing [ 0.197157] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.198272] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.205894] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.206026] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.207009] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.208067] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.210334] acpiphp: Slot [2] registered [ 0.211099] acpiphp: Slot [5] registered [ 0.212079] acpiphp: Slot [6] registered [ 0.213034] acpiphp: Slot [7] registered [ 0.214102] acpiphp: Slot [8] registered [ 0.215148] acpiphp: Slot [9] registered [ 0.216115] acpiphp: Slot [10] registered [ 0.217087] acpiphp: Slot [3] registered [ 0.218096] acpiphp: Slot [4] registered [ 0.219138] acpiphp: Slot [11] registered [ 0.220050] acpiphp: Slot [12] registered [ 0.221071] acpiphp: Slot [13] registered [ 0.222127] acpiphp: Slot [14] registered [ 0.223059] acpiphp: Slot [15] registered [ 0.224062] acpiphp: Slot [16] registered [ 0.225063] acpiphp: Slot [17] registered [ 0.226065] acpiphp: Slot [18] registered [ 0.227027] acpiphp: Slot [19] registered [ 0.227842] acpiphp: Slot [20] registered [ 0.228043] acpiphp: Slot [21] registered [ 0.229111] acpiphp: Slot [22] registered [ 0.230101] acpiphp: Slot [23] registered [ 0.231078] acpiphp: Slot [24] registered [ 0.232153] acpiphp: Slot [25] registered [ 0.233103] acpiphp: Slot [26] registered [ 0.234091] acpiphp: Slot [27] registered [ 0.235116] acpiphp: Slot [28] registered [ 0.236096] acpiphp: Slot [29] registered [ 0.237161] acpiphp: Slot [30] registered [ 0.238076] acpiphp: Slot [31] registered [ 0.239116] PCI host bridge to bus 0000:00 [ 0.241016] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.243027] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.246022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.249018] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.252019] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.255061] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.258269] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.262000] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.265806] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.281012] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.287082] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.289013] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.292020] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.298022] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.303918] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.307861] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.312039] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.318732] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.327013] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.355000] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.361015] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.371185] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.379016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.386020] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.418015] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.430658] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.437017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.445018] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.473015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.487113] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.493015] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.498017] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.509015] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.523472] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.532015] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.547019] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.578035] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.597778] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.609018] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.615014] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.629015] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.640000] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.648016] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.654015] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.676022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.689101] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.693481] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.696416] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.698398] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.700210] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.703552] iommu: Default domain type: Passthrough [ 0.708452] SCSI subsystem initialized [ 0.710127] ACPI: bus type USB registered [ 0.711102] usbcore: registered new interface driver usbfs [ 0.713063] usbcore: registered new interface driver hub [ 0.715163] usbcore: registered new device driver usb [ 0.716140] pps_core: LinuxPPS API ver. 1 registered [ 0.718010] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.721152] PTP clock support registered [ 0.722305] EDAC MC: Ver: 3.0.0 [ 0.724104] PCI: Using ACPI for IRQ routing [ 0.725965] NetLabel: Initializing [ 0.727010] NetLabel: domain hash size = 128 [ 0.729008] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.731077] NetLabel: unlabeled traffic allowed by default [ 0.733362] vgaarb: loaded [ 0.734465] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.736007] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.783176] clocksource: Switched to clocksource kvm-clock [ 0.910310] VFS: Disk quotas dquot_6.6.0 [ 0.912099] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.914471] *** VALIDATE ramfs *** [ 0.915557] *** VALIDATE hugetlbfs *** [ 0.917375] pnp: PnP ACPI init [ 0.919715] pnp: PnP ACPI: found 6 devices [ 0.935373] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.938268] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.940076] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.942106] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.944502] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.947036] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.949564] NET: Registered protocol family 2 [ 0.952125] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.960500] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.964129] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.969493] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.973297] TCP: Hash tables configured (established 65536 bind 65536) [ 0.976304] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.979277] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.981852] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.984685] NET: Registered protocol family 1 [ 0.987569] RPC: Registered named UNIX socket transport module. [ 0.990188] RPC: Registered udp transport module. [ 0.991734] RPC: Registered tcp transport module. [ 0.994167] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.996598] NET: Registered protocol family 44 [ 0.998228] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.000111] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.002307] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.004532] PCI: CLS 0 bytes, default 64 [ 1.006381] Unpacking initramfs... [ 2.788225] debug: unmapping init [mem 0xffff9a4c3cc54000-0xffff9a4c3ffbffff] [ 2.792504] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.794707] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.797410] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.814895] Initialise system trusted keyrings [ 3.820081] Key type blacklist registered [ 3.826336] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.837026] zbud: loaded [ 3.840856] *** VALIDATE nfs *** [ 3.842682] *** VALIDATE nfs4 *** [ 3.846039] pstore: using deflate compression [ 3.852760] Platform Keyring initialized [ 3.973831] NET: Registered protocol family 38 [ 3.976292] Key type asymmetric registered [ 3.981566] Asymmetric key parser 'x509' registered [ 3.983400] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.986376] io scheduler mq-deadline registered [ 3.987775] io scheduler kyber registered [ 3.989409] io scheduler bfq registered [ 3.991483] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.993975] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.996375] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.998621] ACPI: Power Button [PWRF] [ 4.005763] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 4.013748] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 4.029320] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 4.037419] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 4.056247] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 4.086286] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 4.115956] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 4.121550] Non-volatile memory driver v1.3 [ 4.122775] Linux agpgart interface v0.103 [ 4.155529] virtio_blk virtio1: [vda] 145784 512-byte logical blocks (74.6 MB/71.2 MiB) [ 4.158629] vda: detected capacity change from 0 to 74641408 [ 4.177299] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.179820] vdb: detected capacity change from 0 to 1073741824 [ 4.203257] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.206077] vdc: detected capacity change from 0 to 2621440000 [ 4.228665] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.231441] vdd: detected capacity change from 0 to 2621440000 [ 4.271663] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.274317] vde: detected capacity change from 0 to 4294967296 [ 4.294817] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.297630] vdf: detected capacity change from 0 to 4294967296 [ 4.310660] libphy: Fixed MDIO Bus: probed [ 4.321241] usbcore: registered new interface driver usbserial_generic [ 4.323462] usbserial: USB Serial support registered for generic [ 4.325888] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.330656] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.332334] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.335768] mousedev: PS/2 mouse device common for all mice [ 4.346739] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.347374] rtc_cmos 00:05: RTC can wake from S4 [ 4.354082] rtc_cmos 00:05: registered as rtc0 [ 4.355594] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.358582] intel_pstate: CPU model not supported [ 4.359110] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.365824] hid: raw HID events driver (C) Jiri Kosina [ 4.368877] usbcore: registered new interface driver usbhid [ 4.370506] usbhid: USB HID core driver [ 4.371783] drop_monitor: Initializing network drop monitor service [ 4.373797] Initializing XFRM netlink socket [ 4.375587] NET: Registered protocol family 10 [ 4.377981] Segment Routing with IPv6 [ 4.379168] NET: Registered protocol family 17 [ 4.447369] mpls_gso: MPLS GSO support [ 4.450537] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.457972] RAS: Correctable Errors collector initialized. [ 4.459674] AVX version of gcm_enc/dec engaged. [ 4.461220] AES CTR mode by8 optimization enabled [ 4.546805] sched_clock: Marking stable (4546787923, 0)->(5671127342, -1124339419) [ 4.552268] registered taskstats version 1 [ 4.554795] Loading compiled-in X.509 certificates [ 4.557565] zswap: loaded using pool lzo/zbud [ 4.588507] Key type big_key registered [ 4.604757] Key type encrypted registered [ 4.606420] ima: No TPM chip found, activating TPM-bypass! [ 4.608965] ima: Allocated hash algorithm: sha1 [ 4.610642] ima: No architecture policies found [ 4.612495] evm: Initialising EVM extended attributes: [ 4.615402] evm: security.selinux [ 4.617156] evm: security.ima [ 4.618279] evm: security.capability [ 4.620252] evm: HMAC attrs: 0x1 [ 4.623391] rtc_cmos 00:05: setting system clock to 2026-07-15 13:25:25 UTC (1784121925) [ 4.631319] debug: unmapping init [mem 0xffffffff91e03000-0xffffffff91ffffff] [ 4.634690] debug: unmapping init [mem 0xffffffff90b82000-0xffffffff90e58fff] [ 4.647291] Write protecting the kernel read-only data: 28672k [ 4.651363] debug: unmapping init [mem 0xffffffff8f203000-0xffffffff8f3fffff] [ 4.654503] debug: unmapping init [mem 0xffffffff8fb14000-0xffffffff8fbfffff] [ 4.706151] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 4.716970] systemd[1]: Detected virtualization kvm. [ 4.720435] systemd[1]: Detected architecture x86-64. [ 4.722426] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.748691] systemd[1]: No hostname configured. [ 4.750277] systemd[1]: Set hostname to . [ 4.752156] random: systemd: uninitialized urandom read (16 bytes read) [ 4.754342] systemd[1]: Initializing machine ID from random generator. [ 4.857616] random: ln: uninitialized urandom read (6 bytes read) [ 5.072135] random: systemd: uninitialized urandom read (16 bytes read) [ 5.076421] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 5.086594] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ 5.096367] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... Starting Create Volatile Files and Directories... Starting Journal Service... Starting Apply Kernel Variables... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Initrd Root Device. Starting Setup Virtual Console... [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ 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... [ 6.447692] device-mapper: uevent: version 1.0.3 [ 6.450464] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 8.166765] virtio_net virtio0 ens2: renamed from eth0 [ 8.407578] scsi host0: ata_piix [ 8.410279] random: fast init done [ 8.414125] scsi host1: ata_piix [ 8.419882] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 8.427137] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 14.243272] random: crng init done [ 14.245325] random: 7 urandom warning(s) missed due to ratelimiting [ 17.611510] dracut-initqueue[589]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 18.554336] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ 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 Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 20.316980] printk: systemd: 26 output lines suppressed due to ratelimiting [ 20.845739] SELinux: Disabled at runtime. [ 20.923539] 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) [ 20.933896] systemd[1]: Detected virtualization kvm. [ 20.936247] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 21.918246] systemd[1]: initrd-switch-root.service: Succeeded. [ 21.925409] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 21.932593] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 21.939416] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 21.949646] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 21.978249] systemd[1]: Starting Journal Service... Starting Journal Service... [ 21.988345] systemd[1]: Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice User and Session Slice. [ OK ] Reached target rpc_pipefs.target. Mounting POSIX Message Queue File System... [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Kernel Socket. Mounting Huge Pages File System... [ OK ] Stopped target Switch Root. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice system-getty.slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Initrd Root File System. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 22.261660] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. Mounting Kernel Debug File System... [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 23.328954] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 24.445475] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 24.878760] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 25.991329] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 26.244723] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (7s / no limit)[ 30.279316] Key type dns_resolver registered [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 30.739289] NFS: Registering the id_resolver key type [ 30.741722] Key type id_resolver registered [ 30.743603] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ OK ] Started Configure read-only root support. [ 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 dnf makecache --timer. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started irqbalance daemon. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg233-server login: [ 62.876783] libcfs: loading out-of-tree module taints kernel. [ 62.894965] Key type ._llcrypt registered [ 62.896655] Key type .llcrypt registered [ 62.934565] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_hostid [ 70.659228] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 71.229242] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 71.236142] alg: No test for adler32 (adler32-zlib) [ 72.241623] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 72.601793] LNet: Added LNI 192.168.202.133@tcp [8/256/0/180] [ 74.223133] Key type lgssc registered [ 74.850244] Lustre: Echo OBD driver; http://www.lustre.org/ [ 81.211253] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 96.938824] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 102.099612] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 102.110913] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 103.204054] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 103.216531] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 103.256640] Lustre: lustre-MDT0000: new disk, initializing [ 103.288354] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 103.298666] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 104.729634] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 110.857638] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 110.896916] Lustre: 6482: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 [ 110.910715] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 110.913862] Lustre: Skipped 1 previous similar message [ 110.952594] Lustre: lustre-MDT0001: new disk, initializing [ 110.979326] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 110.988165] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 110.993279] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 112.562981] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 115.176772] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 118.787390] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 118.893478] Lustre: lustre-OST0000: new disk, initializing [ 118.896352] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 118.900108] Lustre: 8413:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 118.920782] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 119.291545] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 119.295265] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 119.332977] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 120.973836] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 127.448604] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 127.503082] Lustre: lustre-OST0001: new disk, initializing [ 127.504713] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 127.508052] Lustre: 9489:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 127.533572] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 129.973547] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 136.738890] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 137.194933] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 137.199059] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 137.215729] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 139.564020] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 141.802756] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing check_logdir /tmp/testlogs/ [ 143.615868] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing yml_node [ 145.163375] Lustre: DEBUG MARKER: Client: 2.17.54.162 [ 146.157972] Lustre: DEBUG MARKER: MDS: 2.17.54.162 [ 147.203645] Lustre: DEBUG MARKER: OSS: 2.17.54.162 [ 147.845241] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Wed Jul 15 09:27:48 EDT 2026 [ 153.894459] Lustre: DEBUG MARKER: excepting tests: [ 157.480933] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 162.271582] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 162.274607] 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 [ 162.278696] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 162.783418] 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 [ 162.784116] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 162.786626] Lustre: Skipped 1 previous similar message [ 165.661248] Lustre: server umount lustre-MDT0000 complete [ 168.415733] LustreError: 6473:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122089 with bad export cookie 14016536279976467340 [ 168.417482] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 168.419048] LustreError: 6473:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 168.517227] Lustre: server umount lustre-MDT0001 complete [ 181.255166] Lustre: server umount lustre-OST0000 complete [ 194.673924] Lustre: server umount lustre-OST0001 complete [ 200.817643] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing unload_modules_local [ 202.004199] Key type lgssc unregistered [ 202.151353] LNet: 14750:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 202.156398] LNetError: 14750:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 202.167596] LNet: Removed LNI 192.168.202.133@tcp [ 202.532349] Key type .llcrypt unregistered [ 202.533898] Key type ._llcrypt unregistered [ 211.630677] Key type ._llcrypt registered [ 211.632686] Key type .llcrypt registered [ 211.701463] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_hostid [ 218.868783] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 219.290943] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 219.305822] alg: No test for adler32 (adler32-zlib) [ 220.221772] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 220.334474] LNet: Added LNI 192.168.202.133@tcp [8/256/0/180] [ 221.919139] Key type lgssc registered [ 222.393656] Lustre: Echo OBD driver; http://www.lustre.org/ [ 242.411222] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 247.960484] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 247.979282] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 249.081536] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 249.093269] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 249.132896] Lustre: lustre-MDT0000: new disk, initializing [ 249.190676] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 249.198859] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 250.728685] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 256.513345] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 256.550645] Lustre: 19174: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 [ 256.563268] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 256.565372] Lustre: Skipped 1 previous similar message [ 256.602648] Lustre: lustre-MDT0001: new disk, initializing [ 256.628768] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 256.641292] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 256.644537] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 258.227500] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 260.790842] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 264.615547] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 264.711118] Lustre: lustre-OST0000: new disk, initializing [ 264.714528] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 264.718655] Lustre: 21112:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 264.741347] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 266.995167] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 270.325117] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 270.331085] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 270.370690] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 272.980824] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 273.043920] Lustre: lustre-OST0001: new disk, initializing [ 273.046395] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 273.049645] Lustre: 22136:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 273.073396] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 275.438202] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 276.355624] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 276.360325] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 276.383229] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 281.699603] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 288.097864] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 291.469722] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 09:30:11 (1784122211) === [ 292.351596] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 09:30:12 (1784122212) [ 301.861567] Lustre: Failing over lustre-MDT0000 [ 302.048232] 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 [ 302.053445] Lustre: Skipped 3 previous similar messages [ 302.096531] Lustre: server umount lustre-MDT0000 complete [ 304.245805] LustreError: 19165:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122225 with bad export cookie 8078876128984827328 [ 304.261496] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 304.261733] Lustre: Failing over lustre-MDT0001 [ 304.265386] LustreError: 19165:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 304.542512] Lustre: server umount lustre-MDT0001 complete [ 310.307511] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 314.335798] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4b83558e00 x1870787658233728/t0(0) o250->MGC192.168.202.133@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 [ 314.512510] LustreError: 21106: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. [ 314.523028] LustreError: 21106:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 314.546509] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 316.823521] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 319.973252] 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 [ 319.973266] LustreError: 21107: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. [ 319.991820] Lustre: Skipped 1 previous similar message [ 320.014228] LustreError: 21107:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 321.539764] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 321.636901] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 321.692159] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 321.696619] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 322.722861] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 322.725971] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 322.746052] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 322.764668] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 322.764819] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 323.229346] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 323.746184] Lustre: 16340:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122228/real 1784122228] req@ffff9a4cb9104000 x1870787658232832/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122244 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 325.855413] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122230/real 1784122230] req@ffff9a4cb0805c00 x1870787658233344/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122246 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 325.855412] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122230/real 1784122230] req@ffff9a4cb0805180 x1870787658233216/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122246 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 325.855425] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 325.878513] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 328.159133] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122233/real 1784122233] req@ffff9a4b8355b100 x1870787658233472/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122249 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 328.169854] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 328.422438] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 09:30:48 (1784122248) [ 330.207098] Lustre: 16340:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122235/real 1784122235] req@ffff9a4b83558a80 x1870787658233984/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122251 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 337.759243] Lustre: Failing over lustre-MDT0000 [ 337.932728] Lustre: server umount lustre-MDT0000 complete [ 338.400202] 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 [ 338.402343] LustreError: 25591: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. [ 338.407608] Lustre: Skipped 3 previous similar messages [ 338.415832] LustreError: 25591:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 339.554161] LustreError: 21122:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122260 with bad export cookie 8078876128984843624 [ 339.554530] Lustre: Failing over lustre-MDT0001 [ 339.555398] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 339.559406] LustreError: 21122:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 339.725385] Lustre: server umount lustre-MDT0001 complete [ 343.365796] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 349.664621] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4cbfaf5c00 x1870787658329728/t0(0) o250->MGC192.168.202.133@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 [ 349.784615] LustreError: 25039: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. [ 349.831638] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 349.835778] Lustre: Skipped 1 previous similar message [ 351.469706] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 355.296568] LustreError: 21107: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. [ 355.296590] 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 [ 355.368871] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 355.494180] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 355.551415] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 355.566852] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 357.592859] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 358.631152] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 358.635848] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 358.644859] Lustre: Skipped 4 previous similar messages [ 358.661341] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 358.687422] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 358.688493] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 359.711248] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122264/real 1784122264] req@ffff9a4b82324000 x1870787658329088/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122280 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 359.724055] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 360.047830] Lustre: *** cfs_fail_loc=193, val=0*** [ 362.535296] Lustre: Failing over lustre-MDT0000 [ 362.670701] Lustre: server umount lustre-MDT0000 complete [ 364.001105] 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 [ 364.002192] LustreError: 26489: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. [ 364.007696] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 364.009673] Lustre: Skipped 4 previous similar messages [ 364.022830] LustreError: 26489:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 367.132248] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 367.186767] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 367.305136] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 367.309434] Lustre: Skipped 1 previous similar message [ 369.819752] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 372.707136] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 372.712519] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 372.727093] Lustre: Skipped 4 previous similar messages [ 372.744031] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 372.768116] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 372.771156] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 375.649169] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 09:31:35 (1784122295) [ 382.692829] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 393.461933] Lustre: 30362:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 403.863658] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 405.450867] Lustre: 31494:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 411.347629] Lustre: *** cfs_fail_loc=198, val=0*** [ 417.652631] Lustre: Failing over lustre-MDT0000 [ 417.853332] Lustre: server umount lustre-MDT0000 complete [ 418.783994] 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 [ 418.785046] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 418.785339] LustreError: 26488: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. [ 418.789185] Lustre: Skipped 2 previous similar messages [ 419.624839] LustreError: 19166:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122340 with bad export cookie 8078876128984872632 [ 419.627341] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 419.629992] Lustre: Failing over lustre-MDT0001 [ 419.630401] LustreError: 19166:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 419.795893] Lustre: server umount lustre-MDT0001 complete [ 422.166325] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 424.185101] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 428.426370] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 429.535932] LustreError: 32940:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 429.540839] LustreError: 32940:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9a4c9843dc00 x1870787658494976/t0(0) o250->MGC192.168.202.133@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1784122350 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 429.553343] LustreError: 32940:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 430.048052] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c87225f [ 430.052090] Lustre: MGC192.168.202.133@tcp: Connection restored to 0@lo (at 0@lo) [ 430.063621] Lustre: Skipped 3 previous similar messages [ 430.184382] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 431.931088] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 435.680919] 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 [ 435.686885] Lustre: Skipped 2 previous similar messages [ 435.875545] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 436.005436] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 436.067931] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 436.068296] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 437.902326] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 439.135107] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122344/real 1784122344] req@ffff9a4c9843ce00 x1870787658495616/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122360 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 439.137389] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 439.138127] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 439.146395] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 439.156881] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 439.179236] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 439.179253] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 443.282520] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 09:32:43 (1784122363) [ 453.589191] Lustre: Failing over lustre-MDT0000 [ 453.794571] Lustre: server umount lustre-MDT0000 complete [ 454.623926] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 454.623989] LustreError: 32955: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. [ 454.634490] LustreError: 32955:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 10 previous similar messages [ 455.192443] Lustre: Failing over lustre-MDT0001 [ 455.193364] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122376 with bad export cookie 8078876128984900191 [ 455.193894] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 455.212210] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 455.325339] Lustre: server umount lustre-MDT0001 complete [ 457.207038] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 459.133331] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 462.624000] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 462.652664] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 465.887603] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4b8ba9c700 x1870787658592896/t0(0) o250->MGC192.168.202.133@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 [ 467.636827] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 471.438333] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 471.459127] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 471.519956] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 471.523130] Lustre: Skipped 1 previous similar message [ 471.544022] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 471.606887] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:233 to 0x2c0000400:257) [ 471.610271] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 473.425525] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 474.658317] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 474.659171] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 474.660900] Lustre: Skipped 4 previous similar messages [ 474.676356] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 474.698297] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 474.699149] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 475.679144] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122380/real 1784122380] req@ffff9a4b8ba9f480 x1870787658592256/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122396 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 475.690230] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 483.064584] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 490.772971] Lustre: 38741:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 501.342899] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 502.990563] Lustre: 39874:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 515.069148] Lustre: Failing over lustre-MDT0000 [ 515.184374] Lustre: server umount lustre-MDT0000 complete [ 515.552219] 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 [ 515.553219] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 515.566337] Lustre: Skipped 8 previous similar messages [ 517.161915] Lustre: Failing over lustre-MDT0001 [ 517.162700] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122438 with bad export cookie 8078876128984927715 [ 517.163101] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 517.188338] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 517.361901] Lustre: server umount lustre-MDT0001 complete [ 519.784124] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 523.747672] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 529.044665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 529.088705] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 537.055163] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122441/real 1784122441] req@ffff9a4b839aad80 x1870787658733824/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122457 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 537.066782] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 542.175679] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4b8ba99f80 x1870787658735872/t0(0) o250->MGC192.168.202.133@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 [ 542.304665] LustreError: 21107: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. [ 542.310560] LustreError: 21107:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 542.346234] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 542.351738] Lustre: Skipped 3 previous similar messages [ 544.220343] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 547.997318] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 548.023562] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 548.176994] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:297 to 0x2c0000400:321) [ 548.177073] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:298 to 0x280000400:321) [ 549.939670] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 553.441565] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 553.448926] Lustre: Skipped 4 previous similar messages [ 553.452252] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 553.458105] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 553.477661] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 553.477929] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 560.129709] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 567.963801] Lustre: 44554:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 580.021652] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 593.094141] Lustre: Failing over lustre-MDT0000 [ 593.324993] Lustre: server umount lustre-MDT0000 complete [ 594.399564] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 594.402968] LustreError: Skipped 1 previous similar message [ 594.405054] 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 [ 594.412544] Lustre: Skipped 3 previous similar messages [ 594.782635] LustreError: 20121:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122515 with bad export cookie 8078876128984955239 [ 594.784846] Lustre: Failing over lustre-MDT0001 [ 594.785318] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 594.787064] LustreError: 20121:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 594.927306] Lustre: server umount lustre-MDT0001 complete [ 596.889776] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 599.908183] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 604.146060] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 604.180064] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 612.319125] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122517/real 1784122517] req@ffff9a4b8340aa00 x1870787658857984/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122533 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 612.328689] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 619.489494] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c8864eb [ 619.493869] Lustre: MGC192.168.202.133@tcp: Connection restored to 0@lo (at 0@lo) [ 619.497472] Lustre: Skipped 4 previous similar messages [ 619.632674] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 621.076845] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 624.277077] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 624.295438] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 624.438969] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 624.438978] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:361 to 0x280000400:385) [ 625.933690] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 629.728859] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 629.736327] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 629.753962] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 629.754232] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 632.129587] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 09:35:52 (1784122552) [ 637.524684] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 644.210216] Lustre: 50375:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 644.213828] Lustre: 50375:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 652.773330] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 661.960228] Lustre: Failing over lustre-MDT0000 [ 662.117955] Lustre: server umount lustre-MDT0000 complete [ 663.467288] LustreError: 19165:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122584 with bad export cookie 8078876128984982763 [ 663.468720] Lustre: Failing over lustre-MDT0001 [ 663.468960] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 663.473304] LustreError: 19165:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 663.629178] Lustre: server umount lustre-MDT0001 complete [ 665.885524] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 670.028348] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 673.149418] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 676.864447] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 681.259177] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 681.268129] Lustre: lustre-MDT0000: reset Object Index mappings [ 689.222468] LustreError: 21107:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 689.232754] LustreError: 21107:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 689.258671] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 689.262724] Lustre: Skipped 3 previous similar messages [ 689.288972] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 690.875166] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 691.297679] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 691.300965] Lustre: Skipped 5 previous similar messages [ 694.004778] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 694.013172] Lustre: lustre-MDT0001: reset Object Index mappings [ 694.142547] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 694.142563] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 695.533313] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 696.997252] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 697.000148] Lustre: lustre-MDT0000: Denying connection for new client f9a8c45d-e891-4472-b72d-12e35aa27ad5 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 699.368596] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 699.385588] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 699.385605] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 704.971895] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 09:37:05 (1784122625) [ 714.286496] Lustre: Failing over lustre-MDT0000 [ 714.501492] Lustre: server umount lustre-MDT0000 complete [ 716.027861] LustreError: 22900:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122636 with bad export cookie 8078876128985010287 [ 716.028665] Lustre: Failing over lustre-MDT0001 [ 716.031463] LustreError: 22900:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 716.142735] Lustre: server umount lustre-MDT0001 complete [ 718.244715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 722.007367] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 724.968107] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 728.489319] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 732.582244] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 732.591748] Lustre: lustre-MDT0000: reset Object Index mappings [ 735.199211] 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 [ 735.204958] Lustre: Skipped 13 previous similar messages [ 740.324066] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c893a9c [ 740.478429] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 741.343083] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784122646/real 1784122646] req@ffff9a4b8ca48a80 x1870787659064960/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784122662 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 741.352979] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 37 previous similar messages [ 741.948420] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 745.281791] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 745.293111] Lustre: lustre-MDT0001: reset Object Index mappings [ 745.415917] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 745.421552] LustreError: Skipped 3 previous similar messages [ 745.472719] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 745.473306] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:489 to 0x2c0000400:513) [ 746.488363] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 746.488362] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:521 to 0x280000401:545) [ 746.989926] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 749.639892] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32027: rc = 0 [ 750.692832] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 763.030884] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 09:38:03 (1784122683) [ 771.627897] Lustre: Failing over lustre-MDT0000 [ 771.850548] Lustre: server umount lustre-MDT0000 complete [ 773.260754] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 773.265055] LustreError: Skipped 1 previous similar message [ 773.266742] Lustre: Failing over lustre-MDT0001 [ 773.371440] Lustre: server umount lustre-MDT0001 complete [ 775.306437] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 778.761265] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 782.008946] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 785.486637] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 789.792802] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 789.802083] Lustre: lustre-MDT0000: reset Object Index mappings [ 798.177727] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4cbbded500 x1870787659166976/t0(0) o250->MGC192.168.202.133@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 [ 798.341568] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 799.839601] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 803.167780] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 803.178116] Lustre: lustre-MDT0001: reset Object Index mappings [ 803.346602] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:553 to 0x280000400:577) [ 803.352603] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 805.025800] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 806.512239] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 806.514559] Lustre: Skipped 1 previous similar message [ 806.515789] Lustre: lustre-MDT0000: Denying connection for new client d4e053fe-33d7-417c-8c34-34967b1e302b (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 808.426263] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 808.430571] Lustre: Skipped 1 previous similar message [ 808.444419] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:585 to 0x2c0000401:609) [ 808.445182] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 813.485582] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32035: rc = 0 [ 815.581714] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32006 with flags 0x52: rc = 0 [ 912.465491] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 09:40:32 (1784122832) [ 924.504951] Lustre: Failing over lustre-MDT0000 [ 924.734488] Lustre: server umount lustre-MDT0000 complete [ 925.971563] LustreError: 19166:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122846 with bad export cookie 8078876128985065412 [ 925.972976] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 925.977592] LustreError: 19166:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 925.980710] Lustre: Failing over lustre-MDT0001 [ 926.100056] Lustre: server umount lustre-MDT0001 complete [ 927.901947] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 931.032031] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 933.938326] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 937.356930] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 941.565048] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 941.584080] Lustre: lustre-MDT0000: reset Object Index mappings [ 950.751447] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4c85d06a00 x1870787659328512/t0(0) o250->MGC192.168.202.133@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 [ 950.856812] LustreError: 21106: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. [ 950.863931] LustreError: 21106:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 13 previous similar messages [ 950.874514] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 950.877344] Lustre: Skipped 5 previous similar messages [ 950.892764] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 952.280521] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 952.930366] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 952.935210] Lustre: Skipped 15 previous similar messages [ 955.279884] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 955.401355] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 955.401356] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:617 to 0x2c0000400:641) [ 956.764846] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 958.116346] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 958.121359] Lustre: lustre-MDT0000: Denying connection for new client f637607b-5b9d-4b8a-a577-40cd4d18c136 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 960.488308] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 960.505258] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 960.505572] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 964.899088] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32039: rc = 0 [ 968.033439] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 1031.798793] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 09:42:32 (1784122952) [ 1035.716878] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1035.718700] Lustre: Skipped 1 previous similar message [ 1036.222518] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1036.224394] Lustre: Skipped 273 previous similar messages [ 1041.325557] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 09:42:41 (1784122961) [ 1042.698208] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 1042.699639] Lustre: Skipped 181 previous similar messages [ 1046.690579] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 09:42:47 (1784122967) [ 1062.879799] 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 [ 1062.879837] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1062.879845] LustreError: Skipped 3 previous similar messages [ 1062.880288] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1062.880293] Lustre: Skipped 1 previous similar message [ 1062.885027] Lustre: Skipped 11 previous similar messages [ 1064.535558] Lustre: server umount lustre-MDT0000 complete [ 1065.787183] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784122986 with bad export cookie 8078876128985109638 [ 1065.793148] LustreError: 19164:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1068.000218] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1068.003192] Lustre: Skipped 4 previous similar messages [ 1071.007696] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1071.010499] Lustre: Skipped 1 previous similar message [ 1076.127965] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1076.129949] Lustre: Skipped 1 previous similar message [ 1080.287106] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1080.359661] Lustre: server umount lustre-MDT0001 complete [ 1087.741860] Lustre: server umount lustre-OST0000 complete [ 1103.327144] Lustre: lustre-OST0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1103.377967] Lustre: server umount lustre-OST0001 complete [ 1105.293530] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_hostid [ 1107.529584] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1122.194555] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1125.496980] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1125.581702] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1125.591873] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1125.627789] Lustre: lustre-MDT0000: new disk, initializing [ 1125.656059] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1127.061436] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1131.395583] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1131.435345] Lustre: 75389: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 [ 1131.439749] Lustre: 75389:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1131.450674] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1131.453580] Lustre: Skipped 1 previous similar message [ 1131.497142] Lustre: lustre-MDT0001: new disk, initializing [ 1131.531674] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1131.535458] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1132.945744] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1135.351831] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1137.639258] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1137.717594] Lustre: lustre-OST0000: new disk, initializing [ 1137.719335] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1137.722134] Lustre: 77020:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1139.691738] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1139.695203] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1139.722643] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1139.728902] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1143.953786] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1143.998417] Lustre: lustre-OST0001: new disk, initializing [ 1144.000289] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1144.002819] Lustre: 77889:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1145.194677] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1145.197455] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1145.210066] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1145.890829] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1150.163251] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1151.315629] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1158.328601] Lustre: Failing over lustre-MDT0000 [ 1158.573640] Lustre: server umount lustre-MDT0000 complete [ 1159.726103] Lustre: Failing over lustre-MDT0001 [ 1159.828953] Lustre: server umount lustre-MDT0001 complete [ 1161.604283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1164.661332] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1167.377760] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1170.479235] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1174.125714] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1174.132636] Lustre: lustre-MDT0000: reset Object Index mappings [ 1174.133875] Lustre: Skipped 1 previous similar message [ 1177.055141] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784123081/real 1784123081] req@ffff9a4cbf772300 x1870787659565568/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784123097 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1177.066174] Lustre: 16342:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 42 previous similar messages [ 1184.223558] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4cbf772a00 x1870787659568256/t0(0) o250->MGC192.168.202.133@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 [ 1184.396330] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1185.840070] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1188.686276] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1188.807768] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 1188.807803] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 1190.129585] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1192.199041] Lustre: lustre-MDT0000: Denying connection for new client ba3cea80-9d32-448e-8c72-fe6cd7c43356 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 1193.972097] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 1193.972097] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 1198.871788] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32030: rc = 0 [ 1198.871804] Lustre: *** cfs_fail_loc=190, val=3*** [ 1199.887291] Lustre: *** cfs_fail_loc=190, val=3*** [ 1199.889667] Lustre: Skipped 1 previous similar message [ 1200.910825] Lustre: *** cfs_fail_loc=190, val=3*** [ 1201.953265] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32045 with flags 0x52: rc = 0 [ 1203.935123] Lustre: *** cfs_fail_loc=190, val=3*** [ 1203.936766] Lustre: Skipped 2 previous similar messages [ 1208.817640] Lustre: Failing over lustre-MDT0000 [ 1208.897848] Lustre: server umount lustre-MDT0000 complete [ 1210.068940] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1210.072234] LustreError: Skipped 2 previous similar messages [ 1210.074187] Lustre: Failing over lustre-MDT0001 [ 1210.185247] Lustre: server umount lustre-MDT0001 complete [ 1213.447085] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1219.551523] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4caf5c1500 x1870787659597952/t0(0) o250->MGC192.168.202.133@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 [ 1219.701389] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1221.171575] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1224.449255] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1224.564166] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 1224.564171] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:97) [ 1225.933860] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1227.862927] Lustre: Failing over lustre-MDT0000 [ 1227.865324] LustreError: 83664:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 1227.870070] LustreError: 83664:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 1227.873670] LustreError: 83664:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 8, retries 0, failed: rc = -5 [ 1227.877113] Lustre: 83665:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1227.877203] LustreError: 84923:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 1227.883286] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 1227.890972] LustreError: 83665:0:(client.c:1381:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff9a4cbade8380 x1870787659612544/t0(0) o1000->lustre-MDT0001-osp-MDT0000@0@lo:24/4 lens 304/4320 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 1227.899634] LustreError: 83665:0:(lod_dev.c:351:lod_sub_recreate_llog()) lustre-MDT0000-mdtlov: can't access update_log: rc = -5 [ 1227.997719] Lustre: server umount lustre-MDT0000 complete [ 1229.240739] Lustre: Failing over lustre-MDT0001 [ 1229.243016] LustreError: 84382:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200000009:0x0:0x0]: rc = -5 [ 1229.246786] LustreError: 84382:0:(osp_object.c:618:osp_attr_get()) Skipped 1 previous similar message [ 1229.249063] LustreError: 84382:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0001-mdtlov: can't get id from catalogs: rc = -5 [ 1229.252194] LustreError: 84382:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 5, retries 0, failed: rc = -5 [ 1229.342916] Lustre: server umount lustre-MDT0001 complete [ 1232.604142] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1232.650176] Lustre: *** cfs_fail_loc=190, val=3*** [ 1232.652791] Lustre: Skipped 2 previous similar messages [ 1239.968298] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c8c172d [ 1239.971795] Lustre: MGC192.168.202.133@tcp: Connection restored to 0@lo (at 0@lo) [ 1239.974398] Lustre: Skipped 9 previous similar messages [ 1241.490183] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1241.695148] Lustre: *** cfs_fail_loc=190, val=3*** [ 1241.696812] Lustre: Skipped 2 previous similar messages [ 1244.587048] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1244.697925] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 1244.697929] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:129) [ 1246.092731] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1249.761962] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1249.765242] Lustre: Skipped 1 previous similar message [ 1249.771815] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1249.775406] Lustre: Skipped 1 previous similar message [ 1249.788845] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 1249.788913] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 1253.199863] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32045 with flags 0x52: rc = 0 [ 1253.204872] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/212: rc = 0 [ 1257.840994] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 09:46:18 (1784123178) [ 1267.154847] Lustre: Failing over lustre-MDT0000 [ 1267.357297] Lustre: server umount lustre-MDT0000 complete [ 1268.820201] Lustre: Failing over lustre-MDT0001 [ 1268.939538] Lustre: server umount lustre-MDT0001 complete [ 1270.959337] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1274.415464] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1277.342121] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1280.874027] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1285.156158] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1285.164432] Lustre: lustre-MDT0000: reset Object Index mappings [ 1285.166352] Lustre: Skipped 1 previous similar message [ 1293.791516] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4b8bc32300 x1870787659712768/t0(0) o250->MGC192.168.202.133@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 [ 1293.802967] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 1293.954664] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1293.958636] Lustre: Skipped 3 previous similar messages [ 1295.532080] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1298.617699] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1298.781810] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 1298.781810] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 1300.384488] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1301.962828] Lustre: lustre-MDT0000: Denying connection for new client 419bfd9d-f75c-4561-b1b3-f570b0e595a2 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 1304.054868] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:137 to 0x2c0000401:161) [ 1304.054874] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:138 to 0x280000401:161) [ 1308.729908] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/64044: rc = 0 [ 1308.729928] Lustre: *** cfs_fail_loc=190, val=2*** [ 1308.734234] Lustre: Skipped 6 previous similar messages [ 1311.846356] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 1329.500041] Lustre: Failing over lustre-MDT0000 [ 1329.588324] Lustre: server umount lustre-MDT0000 complete [ 1330.816685] LustreError: 75383:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784123251 with bad export cookie 8078876128985266375 [ 1330.817449] Lustre: Failing over lustre-MDT0001 [ 1330.821451] LustreError: 75383:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 1330.930401] Lustre: server umount lustre-MDT0001 complete [ 1334.255791] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1342.884419] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1343.391171] Lustre: *** cfs_fail_loc=190, val=3*** [ 1343.393065] Lustre: Skipped 23 previous similar messages [ 1346.222222] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1346.440428] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 1346.441974] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 1347.874864] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1349.493694] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:138 to 0x280000401:193) [ 1349.494638] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:137 to 0x2c0000401:193) [ 1356.362213] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 09:47:56 (1784123276) [ 1361.019523] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1367.088177] Lustre: 96131:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1375.721426] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1389.345035] Lustre: Failing over lustre-MDT0000 [ 1389.501103] Lustre: server umount lustre-MDT0000 complete [ 1390.675327] Lustre: Failing over lustre-MDT0001 [ 1390.777288] Lustre: server umount lustre-MDT0001 complete [ 1392.404248] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1395.278708] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1397.922183] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1401.019979] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1404.577322] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1415.277049] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1415.280127] Lustre: Skipped 1 previous similar message [ 1416.709584] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1419.796606] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1419.805507] Lustre: lustre-MDT0001: reset Object Index mappings [ 1419.807726] Lustre: Skipped 2 previous similar messages [ 1419.935140] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:265 to 0x2c0000400:289) [ 1419.935154] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 1421.512704] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1422.014670] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 1422.014745] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 1424.625952] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32040: rc = 0 [ 1424.625961] Lustre: *** cfs_fail_loc=190, val=3*** [ 1424.629547] Lustre: Skipped 2 previous similar messages [ 1424.633331] Lustre: Skipped 4 previous similar messages [ 1427.762328] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 1438.677113] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 09:49:19 (1784123359) [ 1451.110794] Lustre: Failing over lustre-MDT0000 [ 1451.244731] Lustre: server umount lustre-MDT0000 complete [ 1452.533267] Lustre: Failing over lustre-MDT0001 [ 1452.647542] Lustre: server umount lustre-MDT0001 complete [ 1454.447023] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1457.431246] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1459.927171] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1462.898372] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1466.707304] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1477.535472] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4c854aca80 x1870787659979904/t0(0) o250->MGC192.168.202.133@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 [ 1477.541128] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) Skipped 21 previous similar messages [ 1477.649566] LustreError: 86998: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. [ 1477.654405] LustreError: 86998:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 38 previous similar messages [ 1477.665277] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1477.667383] Lustre: Skipped 17 previous similar messages [ 1478.891319] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1481.535354] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1481.651183] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 1481.655105] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:329 to 0x280000400:353) [ 1482.678037] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 1482.678148] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:298 to 0x2c0000401:321) [ 1482.901866] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1505.071315] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 09:50:25 (1784123425) [ 1509.209546] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1514.956656] Lustre: 108826:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1514.959611] Lustre: 108826:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1522.575697] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1545.804961] Lustre: Failing over lustre-MDT0000 [ 1546.099215] Lustre: server umount lustre-MDT0000 complete [ 1547.336507] Lustre: Failing over lustre-MDT0001 [ 1547.583611] Lustre: server umount lustre-MDT0001 complete [ 1549.494686] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1553.165864] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1556.886578] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1560.613426] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1565.485720] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1572.832300] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c9217c9 [ 1572.959407] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1572.962667] Lustre: Skipped 1 previous similar message [ 1574.224830] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1576.963162] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1577.043619] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1577.046406] LustreError: Skipped 10 previous similar messages [ 1577.078128] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 1577.083018] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:393 to 0x2c0000400:417) [ 1578.429986] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1582.578084] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:362 to 0x280000401:385) [ 1582.578109] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 1617.915294] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 09:52:18 (1784123538) [ 1621.750751] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1635.718211] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1672.111831] Lustre: Failing over lustre-MDT0000 [ 1672.336746] Lustre: server umount lustre-MDT0000 complete [ 1673.507723] Lustre: Failing over lustre-MDT0001 [ 1673.626161] Lustre: server umount lustre-MDT0001 complete [ 1675.378262] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1678.300045] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1680.854043] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1683.794912] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1687.126752] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1687.135539] Lustre: lustre-MDT0000: reset Object Index mappings [ 1687.137527] Lustre: Skipped 4 previous similar messages [ 1691.103088] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784123595/real 1784123595] req@ffff9a4b8bf20380 x1870787660266752/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784123611 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1691.104133] 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 [ 1691.109503] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 90 previous similar messages [ 1691.112840] Lustre: Skipped 39 previous similar messages [ 1699.564184] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1702.113934] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1702.216461] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 1702.219194] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:481) [ 1703.454251] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1704.706527] Lustre: lustre-MDT0000: Denying connection for new client 2fd8a91b-2f87-476c-9659-6ed2fa7bd0ed (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 1707.508156] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:426 to 0x280000401:449) [ 1707.508167] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1711.194598] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32010: rc = 0 [ 1711.194633] Lustre: *** cfs_fail_loc=190, val=1*** [ 1711.198100] Lustre: Skipped 35 previous similar messages [ 1714.266512] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 1716.770722] Lustre: Failing over lustre-MDT0000 [ 1716.851905] Lustre: server umount lustre-MDT0000 complete [ 1718.085751] Lustre: Failing over lustre-MDT0001 [ 1718.192337] Lustre: server umount lustre-MDT0001 complete [ 1720.821211] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1727.968140] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c9ccd8b [ 1729.249395] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1731.778244] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1731.881185] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 1731.882728] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:513) [ 1733.074359] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1734.807722] Lustre: Failing over lustre-MDT0000 [ 1734.809377] LustreError: 122665:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 1734.812666] LustreError: 122665:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 1734.815236] LustreError: 122665:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 7, retries 0, failed: rc = -5 [ 1734.818243] Lustre: 122666:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1734.818303] LustreError: 123925:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 1734.821366] Lustre: 122666:0:(ldlm_lib.c:2403:target_recovery_overseer()) Skipped 2 previous similar messages [ 1734.825490] Lustre: lustre-MDT0000-osd: cancel update llog [0x2000013a0:0x1:0x0] [ 1734.832554] LustreError: 122666:0:(client.c:1381:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff9a4b8dba5c00 x1870787660311936/t0(0) o1000->lustre-MDT0001-osp-MDT0000@0@lo:24/4 lens 304/4320 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 1734.841906] LustreError: 122666:0:(lod_dev.c:351:lod_sub_recreate_llog()) lustre-MDT0000-mdtlov: can't access update_log: rc = -5 [ 1734.926792] Lustre: server umount lustre-MDT0000 complete [ 1736.024527] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1736.027327] LustreError: Skipped 8 previous similar messages [ 1736.028843] Lustre: Failing over lustre-MDT0001 [ 1736.118565] Lustre: server umount lustre-MDT0001 complete [ 1738.604366] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1745.375416] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4c854af480 x1870787660313600/t0(0) o250->MGC192.168.202.133@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 [ 1745.381650] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) Skipped 12 previous similar messages [ 1746.897927] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1749.680718] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1749.807603] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:545) [ 1749.811148] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 1751.153732] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1752.865842] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1752.868338] Lustre: Skipped 37 previous similar messages [ 1752.886785] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:481) [ 1752.886811] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:426 to 0x280000401:481) [ 1757.091616] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 09:54:37 (1784123677) [ 1761.016407] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 1774.137294] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1775.216211] Lustre: 128862:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1775.220631] Lustre: 128862:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 4 previous similar messages [ 1782.824058] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 09:55:03 (1784123703) [ 1784.117737] Lustre: *** cfs_fail_loc=195, val=0*** [ 1785.007727] Lustre: Failing over lustre-OST0000 [ 1785.053281] Lustre: server umount lustre-OST0000 complete [ 1788.082945] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1789.664325] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1789.666509] Lustre: Skipped 7 previous similar messages [ 1789.670482] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1789.675137] Lustre: Skipped 7 previous similar messages [ 1790.049131] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1985.015728] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 09:58:25 (1784123905) [ 1986.766399] Lustre: *** cfs_fail_loc=196, val=0*** [ 1986.767747] Lustre: Skipped 63 previous similar messages [ 1988.948557] Lustre: Failing over lustre-OST0000 [ 1989.013974] Lustre: server umount lustre-OST0000 complete [ 1992.358521] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1992.440249] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1992.442686] Lustre: Skipped 6 previous similar messages [ 1994.833282] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2186.118658] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 10:01:46 (1784124106) [ 2188.052528] Lustre: *** cfs_fail_loc=196, val=0*** [ 2188.054737] Lustre: Skipped 63 previous similar messages [ 2190.095817] Lustre: *** cfs_fail_loc=196, val=0*** [ 2190.097905] Lustre: Skipped 703 previous similar messages [ 2193.049687] Lustre: Failing over lustre-OST0000 [ 2193.113497] Lustre: server umount lustre-OST0000 complete [ 2193.375542] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 2193.375826] LustreError: 77003: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. [ 2193.379678] LustreError: Skipped 7 previous similar messages [ 2193.384680] LustreError: 77003:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 20 previous similar messages [ 2197.278273] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2197.393646] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 2199.527843] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2204.127919] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2207.714090] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2207.716253] Lustre: Skipped 1 previous similar message [ 2209.010691] Lustre: server umount lustre-MDT0000 complete [ 2210.240609] LustreError: 76184:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784124131 with bad export cookie 8078876128986321415 [ 2210.245155] LustreError: 76184:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 2210.336753] Lustre: server umount lustre-MDT0001 complete [ 2222.042110] Lustre: server umount lustre-OST0000 complete [ 2233.684931] Lustre: server umount lustre-OST0001 complete [ 2237.361939] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 10:02:37 (1784124157) [ 2243.596089] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_hostid [ 2246.375883] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2261.360915] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2265.041139] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2265.126883] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2265.137351] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2265.176173] Lustre: lustre-MDT0000: new disk, initializing [ 2265.199181] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2265.202477] Lustre: Skipped 11 previous similar messages [ 2265.207702] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2266.594293] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2270.821604] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2270.864436] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2270.866645] Lustre: Skipped 1 previous similar message [ 2270.904118] Lustre: lustre-MDT0001: new disk, initializing [ 2270.927993] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2270.931810] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2272.256585] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2274.451061] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2276.613223] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2276.688843] Lustre: lustre-OST0000: new disk, initializing [ 2276.690596] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2276.693145] Lustre: 140636:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2277.868970] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2277.872251] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2277.893836] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2278.677598] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2282.958983] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2283.002651] Lustre: lustre-OST0001: new disk, initializing [ 2283.004871] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2283.008314] Lustre: 141509:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2284.202652] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2284.206263] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2284.221194] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2284.868876] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2289.210258] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2290.440553] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2297.942495] Lustre: Failing over lustre-MDT0000 [ 2298.126033] Lustre: server umount lustre-MDT0000 complete [ 2299.342422] Lustre: Failing over lustre-MDT0001 [ 2299.447867] Lustre: server umount lustre-MDT0001 complete [ 2301.334896] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2304.700896] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2307.925106] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2311.282403] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2315.196708] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2315.207635] Lustre: lustre-MDT0000: reset Object Index mappings [ 2315.210044] Lustre: Skipped 1 previous similar message [ 2315.743125] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784124220/real 1784124220] req@ffff9a4b89870e00 x1870787660743808/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784124236 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2315.743187] 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 [ 2315.752768] Lustre: 16339:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 21 previous similar messages [ 2315.757638] Lustre: Skipped 18 previous similar messages [ 2324.959390] LustreError: 16338:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9a4b84a66d80 x1870787660746496/t0(0) o250->MGC192.168.202.133@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 [ 2326.443883] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2329.457339] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2329.591846] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 2329.591969] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2330.932375] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2334.705593] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 2334.705606] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2348.092084] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 10:04:28 (1784124268) [ 2353.097376] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2359.315864] Lustre: 149746:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2359.319794] Lustre: 149746:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2367.518487] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2377.718550] Lustre: Failing over lustre-MDT0000 [ 2377.733419] Lustre: *** cfs_fail_loc=199, val=0*** [ 2377.734845] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 2377.739854] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 2377.745271] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 2377.749865] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 2377.753768] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 2377.758261] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 2377.762788] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 2377.766988] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 2377.770737] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 2377.775422] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 2377.778080] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 2377.782450] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 2377.786423] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 2377.790819] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 2377.795069] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 2377.799367] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 2377.803912] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 2377.808409] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 2377.812510] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 2377.817257] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 2377.822628] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 2377.826194] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 2377.829630] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 2377.835041] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 2377.839677] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 2377.845573] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 2377.850512] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 2377.855817] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 2377.860927] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 2377.865645] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 2377.870270] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 2377.874480] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 2377.881837] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 2377.887257] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 2377.892177] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 2377.896888] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 2377.901174] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 2377.905765] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 2377.911123] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 2377.916504] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 2377.921102] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 2377.925330] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 2377.929957] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 2377.933236] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 2377.936962] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 2377.941333] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 2377.946870] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 2377.952824] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 2377.958556] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 2377.964577] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 2377.969171] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 2377.973509] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 2377.978222] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 2377.982757] Lustre: 151188:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 2378.089733] Lustre: server umount lustre-MDT0000 complete [ 2379.559634] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2379.563046] LustreError: Skipped 2 previous similar messages [ 2379.563523] Lustre: Failing over lustre-MDT0001 [ 2379.573296] Lustre: *** cfs_fail_loc=199, val=0*** [ 2379.574390] Lustre: Skipped 53 previous similar messages [ 2379.575534] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 2379.578567] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 2379.581838] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 2379.585314] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 2379.588180] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 2379.591125] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 2379.593973] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 2379.596986] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 2379.600152] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 2379.603454] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 2379.607473] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 2379.612235] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 2379.615604] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 2379.619611] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 2379.623408] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 2379.627549] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 2379.632802] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 2379.636192] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 2379.640202] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 2379.644507] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 2379.649174] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 2379.652977] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 2379.656760] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 2379.661734] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 2379.666316] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 2379.670802] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 2379.674888] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 2379.682152] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 2379.686203] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 2379.689980] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 2379.694134] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 2379.697692] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 2379.701736] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 2379.706213] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 2379.710195] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 2379.714949] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 2379.719923] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 2379.724799] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 2379.729847] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 2379.733116] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 2379.738851] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 2379.743182] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 2379.747238] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 2379.752094] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 2379.756485] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 2379.760500] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 2379.764389] Lustre: 151389:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 2379.879810] Lustre: server umount lustre-MDT0001 complete [ 2383.353989] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2383.413963] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 2383.422212] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 2383.430145] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 2383.436503] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 2383.442507] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 2383.446949] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 2383.452321] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 2383.457231] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 2383.461696] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 2383.466724] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 2383.474282] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 2383.480848] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 2383.487669] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 2383.492534] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 2383.497248] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 2383.501925] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 2383.507942] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 2383.512862] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 2383.518253] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 2383.522935] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 2383.529125] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 2383.535159] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 2383.538713] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 2383.544261] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 2383.550332] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 2383.556961] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 2383.562076] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 2383.568095] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 2383.572838] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 2383.577931] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 2383.583369] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 2383.588546] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 2383.592302] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 2383.598536] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 2383.604660] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 2383.608243] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 2383.612689] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 2383.616927] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 2383.620904] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 2383.625768] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 2383.631234] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 2383.635241] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 2383.639711] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 2383.643168] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 2383.647907] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 2383.652449] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 2383.656035] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 2383.660359] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 2383.664776] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 2383.669329] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 2383.673387] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 2383.678115] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 2383.681980] Lustre: 151884:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 2389.984497] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x701def091c9f5401 [ 2389.987320] Lustre: MGC192.168.202.133@tcp: Connection restored to 0@lo (at 0@lo) [ 2389.990070] Lustre: Skipped 15 previous similar messages [ 2391.542901] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2394.514983] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2394.547160] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 2394.551346] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 2394.554963] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 2394.560488] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 2394.565502] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 2394.570292] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 2394.574636] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 2394.578711] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 2394.583813] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 2394.590038] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 2394.595826] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 2394.602859] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 2394.607882] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 2394.613186] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 2394.617730] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 2394.621314] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 2394.625887] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 2394.634803] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 2394.640677] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 2394.645198] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 2394.650220] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 2394.656183] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 2394.661178] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 2394.667093] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 2394.673543] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 2394.678595] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 2394.683622] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 2394.690563] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 2394.694924] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 2394.699627] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 2394.704100] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 2394.709283] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 2394.713958] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 2394.719588] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 2394.723414] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 2394.729691] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 2394.734297] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 2394.737890] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 2394.741375] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 2394.744861] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 2394.748556] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 2394.751753] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 2394.755491] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 2394.760090] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 2394.763314] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 2394.766881] Lustre: 152630:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 2394.892579] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 2394.892591] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 2396.320309] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2397.108411] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2397.111301] Lustre: Skipped 3 previous similar messages [ 2397.112882] Lustre: lustre-MDT0000: Denying connection for new client 5e59d114-79b0-4c89-bf50-1b8e6a203147 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2400.231929] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 2400.236050] Lustre: Skipped 3 previous similar messages [ 2400.250582] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 2400.250593] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 2405.071474] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 10:05:25 (1784124325) [ 2405.394102] Lustre: *** cfs_fail_loc=19d, val=0*** [ 2405.395562] Lustre: Skipped 123 previous similar messages [ 2406.007826] Lustre: Failing over lustre-MDT0000 [ 2406.240872] Lustre: server umount lustre-MDT0000 complete [ 2411.330038] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2412.848556] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2414.140085] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 10:05:34 (1784124334) [ 2416.632600] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 2416.632896] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 2416.641207] Lustre: *** cfs_fail_loc=19e, val=0*** [ 2417.277971] Lustre: Failing over lustre-MDT0000 [ 2417.497840] Lustre: server umount lustre-MDT0000 complete [ 2422.896637] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2424.499439] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2425.768594] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 10:05:46 (1784124346) [ 2428.418775] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 2428.418989] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 2437.160315] Lustre: Failing over lustre-MDT0000 [ 2437.306906] Lustre: server umount lustre-MDT0000 complete [ 2438.553724] Lustre: Failing over lustre-MDT0001 [ 2438.659924] Lustre: server umount lustre-MDT0001 complete [ 2441.539696] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2450.312677] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2453.152230] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2453.267233] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2453.267255] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2454.608586] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2455.354957] Lustre: lustre-MDT0000: Denying connection for new client eaab59a8-6376-4d8a-92b9-80003ebd7aec (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2458.419625] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 2458.419634] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 2461.561776] Lustre: Failing over lustre-MDT0000 [ 2461.642933] Lustre: server umount lustre-MDT0000 complete [ 2462.884705] Lustre: Failing over lustre-MDT0001 [ 2462.991031] Lustre: server umount lustre-MDT0001 complete [ 2465.857940] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2473.922312] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2476.943624] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2477.101482] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2477.108122] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2478.407366] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2479.467047] Lustre: lustre-MDT0000: Denying connection for new client ed375c87-3213-47f3-8c88-49b3331a35f1 (at 192.168.202.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2482.163499] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:289) [ 2482.163502] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 2486.908710] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 10:06:47 (1784124407) [ 2490.849607] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2494.938533] Lustre: server umount lustre-MDT0000 complete [ 2496.381317] Lustre: server umount lustre-MDT0001 complete [ 2507.851913] Lustre: server umount lustre-OST0000 complete [ 2518.363527] Lustre: server umount lustre-OST0001 complete [ 2520.708329] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2523.726252] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2539.167352] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2544.287329] LustreError: 161355:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.133@tcp: failed processing log, type 4: rc = -110 [ 2575.973705] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2581.963102] Lustre: Failing over lustre-OST0000 [ 2582.202811] Lustre: server umount lustre-OST0000 complete [ 2588.963677] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2599.707708] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2615.391375] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2620.511443] LustreError: 162879:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.133@tcp: failed processing log, type 4: rc = -110 [ 2649.212522] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2653.167307] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 10:09:33 (1784124573) [ 2660.188050] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2665.950152] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2666.282763] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 2668.554346] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2673.203100] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2673.441550] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:257) [ 2675.597315] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2679.953008] hrtimer: interrupt took 4990232 ns [ 2686.069714] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2689.602434] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2691.558552] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 2691.566547] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:321) [ 2694.331600] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2698.184577] Lustre: *** cfs_fail_loc=193, val=0*** [ 2699.181785] Lustre: Failing over lustre-MDT0000 [ 2699.232980] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2699.237168] Lustre: Skipped 4 previous similar messages [ 2699.349510] Lustre: server umount lustre-MDT0000 complete [ 2701.795543] Lustre: *** cfs_fail_loc=193, val=0*** [ 2701.798542] Lustre: Skipped 1 previous similar message [ 2703.879316] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2704.112852] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2704.118032] Lustre: Skipped 7 previous similar messages [ 2705.930695] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2709.509331] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 2709.510104] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:353) [ 2709.528895] Lustre: *** cfs_fail_loc=19f, val=0*** [ 2709.530920] Lustre: Skipped 5 previous similar messages [ 2709.539239] Lustre: *** cfs_fail_loc=19f, val=0*** [ 2709.542951] Lustre: Skipped 28 previous similar messages [ 2709.545326] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 2719.139305] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 10:10:39 (1784124639) [ 2720.436825] Lustre: Failing over lustre-MDT0000 [ 2720.627454] Lustre: server umount lustre-MDT0000 complete [ 2722.242350] Lustre: Failing over lustre-MDT0001 [ 2722.390309] Lustre: server umount lustre-MDT0001 complete [ 2723.726576] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2727.170694] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2732.704865] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000400:0x1:0x0]/49 with flags 0x4a: rc = 0 [ 2732.709749] Lustre: 169563:0:(lod_sub_object.c:941:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't open llog [0x200000400:0x1:0x0]: rc = -115 [ 2732.716908] LustreError: 169563:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osd: get update log duration 0, retries 0, failed: rc = -115 [ 2732.721427] LustreError: 169563:0:(lod_dev.c:511:lod_sub_recovery_thread()) Skipped 1 previous similar message [ 2734.665985] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2739.096500] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2741.349749] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2743.957370] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 2745.036698] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:385) [ 2745.041643] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 2745.463716] LustreError: 170285:0:(update_trans.c:1080:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 2745.494125] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:289) [ 2745.497684] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 2752.164785] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 10:11:12 (1784124672) [ 2754.530803] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2759.863211] Lustre: server umount lustre-MDT0000 complete [ 2761.673638] Lustre: server umount lustre-MDT0001 complete [ 2774.033385] Lustre: server umount lustre-OST0000 complete [ 2786.208571] Lustre: server umount lustre-OST0001 complete [ 2789.071950] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2793.350347] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2793.491584] LustreError: 172644: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. [ 2793.504425] LustreError: 172644:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 48 previous similar messages [ 2795.112884] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2797.394803] Lustre: Failing over lustre-MDT0000 [ 2797.401177] LustreError: 172679:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 2797.406548] LustreError: 172679:0:(osp_object.c:618:osp_attr_get()) Skipped 2 previous similar messages [ 2797.410617] LustreError: 172679:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 2797.415260] LustreError: 172679:0:(lod_sub_object.c:917:lod_sub_prep_llog()) Skipped 1 previous similar message [ 2797.418457] LustreError: 172679:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 4, retries 0, failed: rc = -5 [ 2797.544612] Lustre: server umount lustre-MDT0000 complete [ 2800.243230] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2805.728062] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2807.347853] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2810.265040] Lustre: DEBUG MARKER: === sanity-scrub: start setup 10:12:10 (1784124730) === [ 2811.110191] LustreError: 174313:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 2811.116237] LustreError: 174313:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 2811.120299] LustreError: 174313:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 5, retries 0, failed: rc = -5 [ 2811.262095] Lustre: server umount lustre-MDT0000 complete [ 2835.886168] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_hostid [ 2843.736304] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2888.247469] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing load_modules_local [ 2901.698155] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2901.904522] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2901.920386] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2901.986504] Lustre: lustre-MDT0000: new disk, initializing [ 2902.046685] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2902.049713] Lustre: Skipped 23 previous similar messages [ 2902.061223] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2905.724756] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2915.929923] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2916.042753] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2916.058296] Lustre: Skipped 1 previous similar message [ 2916.122338] Lustre: lustre-MDT0001: new disk, initializing [ 2916.206779] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2916.217722] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2919.337257] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2923.416325] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2930.277990] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2930.444570] Lustre: lustre-OST0000: new disk, initializing [ 2930.447511] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2930.456919] Lustre: 181610:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2932.363062] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2932.369182] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2932.429304] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2933.820813] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2943.189533] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2943.280574] Lustre: lustre-OST0001: new disk, initializing [ 2943.284260] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2943.289406] Lustre: 182631:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2944.793039] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2944.803664] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2944.843702] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2947.892721] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2955.271147] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2957.725923] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2961.296529] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 10:14:41 (1784124881) === [ 2962.347880] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 2814 sec ========= 10:14:42 (1784124882) [ 2963.492810] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 10:14:43 (1784124883) === [ 2965.711359] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 10:14:45 (1784124885) === [ 2970.598881] 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 [ 2970.616630] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2970.616980] Lustre: Skipped 38 previous similar messages [ 2970.631828] Lustre: Skipped 10 previous similar messages [ 2974.563285] Lustre: server umount lustre-MDT0000 complete [ 2980.061809] LustreError: 181085:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784124900 with bad export cookie 8078876128986544288 [ 2980.063719] LustreError: MGC192.168.202.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2980.066058] LustreError: 181085:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 12 previous similar messages [ 2980.078728] LustreError: Skipped 8 previous similar messages [ 2980.255507] Lustre: server umount lustre-MDT0001 complete [ 2995.372686] Lustre: server umount lustre-OST0000 complete [ 2996.191277] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784124901/real 1784124901] req@ffff9a4b83c6c700 x1870787661272064/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784124917 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2996.205253] Lustre: 16341:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 48 previous similar messages [ 3001.037535] Lustre: server umount lustre-OST0001 complete [ 3011.395619] Lustre: DEBUG MARKER: oleg233-server.virtnet: executing unload_modules_local [ 3013.236469] Key type lgssc unregistered [ 3013.394315] LNet: 186041:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3013.402630] LNetError: 186041:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3013.419817] LNet: Removed LNI 192.168.202.133@tcp [ 3014.002160] Key type .llcrypt unregistered [ 3014.004046] Key type ._llcrypt unregistered