[ 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 470695309 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002344] x2apic enabled [ 0.003006] Switched APIC routing to physical x2apic. [ 0.004011] kvm-guest: setup PV IPIs [ 0.007000] ..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.007023] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008012] pid_max: default: 32768 minimum: 301 [ 0.009131] LSM: Security Framework initializing [ 0.010045] Yama: becoming mindful. [ 0.011030] SELinux: Initializing. [ 0.012057] *** VALIDATE selinux *** [ 0.020661] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025356] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026146] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027098] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028100] *** VALIDATE tmpfs *** [ 0.030196] *** VALIDATE proc *** [ 0.031256] *** VALIDATE cgroup *** [ 0.032008] *** VALIDATE cgroup2 *** [ 0.033267] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034144] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035006] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036024] Spectre V2 : User space: Vulnerable [ 0.037007] Speculative Store Bypass: Vulnerable [ 0.040284] debug: unmapping init [mem 0xffffffffa6059000-0xffffffffa6060fff] [ 0.042177] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.043651] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.044022] ... version: 2 [ 0.044980] ... bit width: 48 [ 0.045012] ... generic registers: 4 [ 0.046000] ... value mask: 0000ffffffffffff [ 0.046019] ... max period: 00007fffffffffff [ 0.047013] ... fixed-purpose events: 3 [ 0.047973] ... event mask: 000000070000000f [ 0.048285] rcu: Hierarchical SRCU implementation. [ 0.050419] smp: Bringing up secondary CPUs ... [ 0.051534] x86: Booting SMP configuration: [ 0.052021] .... node #0, CPUs: #1 #2 #3 [ 0.055165] smp: Brought up 1 node, 4 CPUs [ 0.057012] smpboot: Max logical packages: 1 [ 0.058009] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.136012] node 0 deferred pages initialised in 75ms [ 0.139010] devtmpfs: initialized [ 0.140206] x86/mm: Memory block size: 128MB [ 0.143326] gcov: version magic: 0x41383552 [ 0.145162] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.148109] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.150352] pinctrl core: initialized pinctrl subsystem [ 0.152179] [ 0.152785] ************************************************************* [ 0.155012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.158012] ** ** [ 0.160012] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.163010] ** ** [ 0.165010] ** This means that this kernel is built to expose internal ** [ 0.168011] ** IOMMU data structures, which may compromise security on ** [ 0.170011] ** your system. ** [ 0.172024] ** ** [ 0.175011] ** If you see this message and you are not debugging the ** [ 0.177011] ** kernel, report this immediately to your vendor! ** [ 0.179012] ** ** [ 0.181012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.183011] ************************************************************* [ 0.186755] NET: Registered protocol family 16 [ 0.188437] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.191065] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.193062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.198050] cpuidle: using governor menu [ 0.200000] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.201689] PCI: Using configuration type 1 for base access [ 0.203096] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.214054] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.216095] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.219128] cryptd: max_cpu_qlen set to 1000 [ 0.225257] ACPI: Added _OSI(Module Device) [ 0.227016] ACPI: Added _OSI(Processor Device) [ 0.229007] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.229946] ACPI: Added _OSI(Processor Aggregator Device) [ 0.233327] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.237326] ACPI: Interpreter enabled [ 0.237904] ACPI: PM: (supports S0 S3 S4 S5) [ 0.239026] ACPI: Using IOAPIC for interrupt routing [ 0.240065] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.243269] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.250610] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.253031] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.255024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.258030] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.262177] acpiphp: Slot [2] registered [ 0.263037] acpiphp: Slot [5] registered [ 0.263938] acpiphp: Slot [6] registered [ 0.264062] acpiphp: Slot [7] registered [ 0.264892] acpiphp: Slot [8] registered [ 0.265066] acpiphp: Slot [9] registered [ 0.266066] acpiphp: Slot [10] registered [ 0.267013] acpiphp: Slot [3] registered [ 0.267870] acpiphp: Slot [4] registered [ 0.269078] acpiphp: Slot [11] registered [ 0.270063] acpiphp: Slot [12] registered [ 0.270927] acpiphp: Slot [13] registered [ 0.272055] acpiphp: Slot [14] registered [ 0.272918] acpiphp: Slot [15] registered [ 0.274092] acpiphp: Slot [16] registered [ 0.275090] acpiphp: Slot [17] registered [ 0.276106] acpiphp: Slot [18] registered [ 0.278111] acpiphp: Slot [19] registered [ 0.279099] acpiphp: Slot [20] registered [ 0.281094] acpiphp: Slot [21] registered [ 0.282106] acpiphp: Slot [22] registered [ 0.283091] acpiphp: Slot [23] registered [ 0.285090] acpiphp: Slot [24] registered [ 0.286089] acpiphp: Slot [25] registered [ 0.287060] acpiphp: Slot [26] registered [ 0.288086] acpiphp: Slot [27] registered [ 0.288947] acpiphp: Slot [28] registered [ 0.290057] acpiphp: Slot [29] registered [ 0.290969] acpiphp: Slot [30] registered [ 0.292074] acpiphp: Slot [31] registered [ 0.292906] PCI host bridge to bus 0000:00 [ 0.294017] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.296022] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.298024] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.300022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.303026] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.305024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.306179] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.309540] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.313337] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.322725] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.328096] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.330017] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.332017] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.335018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.337659] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.340818] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.343047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.346589] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.351015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.363016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.368017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.374971] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.380016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.386017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.408019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.420185] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.432020] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.444016] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.469019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.480550] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.486016] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.491016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.504017] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.517413] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.526077] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.533065] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.545015] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.555014] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.565019] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.576025] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.592016] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.604332] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.609015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.618015] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.632022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.644492] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.647403] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.650376] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.653400] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.656273] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.661078] iommu: Default domain type: Passthrough [ 0.663550] SCSI subsystem initialized [ 0.665149] ACPI: bus type USB registered [ 0.666118] usbcore: registered new interface driver usbfs [ 0.668080] usbcore: registered new interface driver hub [ 0.671097] usbcore: registered new device driver usb [ 0.672197] pps_core: LinuxPPS API ver. 1 registered [ 0.674012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.676048] PTP clock support registered [ 0.678072] EDAC MC: Ver: 3.0.0 [ 0.679423] PCI: Using ACPI for IRQ routing [ 0.680785] NetLabel: Initializing [ 0.682011] NetLabel: domain hash size = 128 [ 0.683008] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.684074] NetLabel: unlabeled traffic allowed by default [ 0.686161] vgaarb: loaded [ 0.687119] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.688000] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.694512] clocksource: Switched to clocksource kvm-clock [ 0.800671] VFS: Disk quotas dquot_6.6.0 [ 0.802259] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.805032] *** VALIDATE ramfs *** [ 0.806364] *** VALIDATE hugetlbfs *** [ 0.808100] pnp: PnP ACPI init [ 0.811615] pnp: PnP ACPI: found 6 devices [ 0.827255] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.830806] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.832297] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.834350] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.836811] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.839308] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.842521] NET: Registered protocol family 2 [ 0.845261] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.850525] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.854437] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.860267] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.864386] TCP: Hash tables configured (established 65536 bind 65536) [ 0.867825] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.871428] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.874743] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.878303] NET: Registered protocol family 1 [ 0.881255] RPC: Registered named UNIX socket transport module. [ 0.883673] RPC: Registered udp transport module. [ 0.885528] RPC: Registered tcp transport module. [ 0.887143] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.889624] NET: Registered protocol family 44 [ 0.890643] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.892083] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.893593] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.895240] PCI: CLS 0 bytes, default 64 [ 0.896744] Unpacking initramfs... [ 2.258695] debug: unmapping init [mem 0xffff9873fcc54000-0xffff9873fffbffff] [ 2.261186] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.262550] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.264668] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.769968] Initialise system trusted keyrings [ 2.771421] Key type blacklist registered [ 2.773060] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.784736] zbud: loaded [ 2.788721] *** VALIDATE nfs *** [ 2.790022] *** VALIDATE nfs4 *** [ 2.791493] pstore: using deflate compression [ 2.794576] Platform Keyring initialized [ 2.900367] NET: Registered protocol family 38 [ 2.901869] Key type asymmetric registered [ 2.903198] Asymmetric key parser 'x509' registered [ 2.904441] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.907409] io scheduler mq-deadline registered [ 2.909113] io scheduler kyber registered [ 2.910599] io scheduler bfq registered [ 2.912508] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.915500] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.918186] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.921254] ACPI: Power Button [PWRF] [ 2.928711] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.935890] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.948066] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.955109] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.969470] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.996235] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.023650] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.028337] Non-volatile memory driver v1.3 [ 3.029684] Linux agpgart interface v0.103 [ 3.059091] virtio_blk virtio1: [vda] 134472 512-byte logical blocks (68.8 MB/65.7 MiB) [ 3.061560] vda: detected capacity change from 0 to 68849664 [ 3.075311] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.077662] vdb: detected capacity change from 0 to 1073741824 [ 3.090721] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.093068] vdc: detected capacity change from 0 to 2621440000 [ 3.108081] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.111285] vdd: detected capacity change from 0 to 2621440000 [ 3.129509] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.132498] vde: detected capacity change from 0 to 4294967296 [ 3.146057] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.149191] vdf: detected capacity change from 0 to 4294967296 [ 3.156645] libphy: Fixed MDIO Bus: probed [ 3.164373] usbcore: registered new interface driver usbserial_generic [ 3.166440] usbserial: USB Serial support registered for generic [ 3.168357] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.172465] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.174049] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.176292] mousedev: PS/2 mouse device common for all mice [ 3.178787] rtc_cmos 00:05: RTC can wake from S4 [ 3.181347] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.181524] rtc_cmos 00:05: registered as rtc0 [ 3.186777] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.186885] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.192382] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.192806] intel_pstate: CPU model not supported [ 3.198834] hid: raw HID events driver (C) Jiri Kosina [ 3.200845] usbcore: registered new interface driver usbhid [ 3.203554] usbhid: USB HID core driver [ 3.205172] drop_monitor: Initializing network drop monitor service [ 3.207802] Initializing XFRM netlink socket [ 3.210140] NET: Registered protocol family 10 [ 3.213058] Segment Routing with IPv6 [ 3.214379] NET: Registered protocol family 17 [ 3.216493] mpls_gso: MPLS GSO support [ 3.220876] RAS: Correctable Errors collector initialized. [ 3.222794] AVX version of gcm_enc/dec engaged. [ 3.224613] AES CTR mode by8 optimization enabled [ 3.298581] sched_clock: Marking stable (3298544739, 0)->(4148348273, -849803534) [ 3.301096] registered taskstats version 1 [ 3.303153] Loading compiled-in X.509 certificates [ 3.304432] zswap: loaded using pool lzo/zbud [ 3.329842] Key type big_key registered [ 3.343743] Key type encrypted registered [ 3.344850] ima: No TPM chip found, activating TPM-bypass! [ 3.346281] ima: Allocated hash algorithm: sha1 [ 3.347442] ima: No architecture policies found [ 3.348631] evm: Initialising EVM extended attributes: [ 3.349976] evm: security.selinux [ 3.350816] evm: security.ima [ 3.351518] evm: security.capability [ 3.352378] evm: HMAC attrs: 0x1 [ 3.354323] rtc_cmos 00:05: setting system clock to 2026-09-05 09:39:21 UTC (1788601161) [ 3.359912] debug: unmapping init [mem 0xffffffffa7003000-0xffffffffa71fffff] [ 3.362145] debug: unmapping init [mem 0xffffffffa5d82000-0xffffffffa6058fff] [ 3.370132] Write protecting the kernel read-only data: 28672k [ 3.373071] debug: unmapping init [mem 0xffffffffa4403000-0xffffffffa45fffff] [ 3.375217] debug: unmapping init [mem 0xffffffffa4d14000-0xffffffffa4dfffff] [ 3.407867] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.413646] systemd[1]: Detected virtualization kvm. [ 3.415322] systemd[1]: Detected architecture x86-64. [ 3.416641] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.441458] systemd[1]: No hostname configured. [ 3.442640] systemd[1]: Set hostname to . [ 3.444183] random: systemd: uninitialized urandom read (16 bytes read) [ 3.446270] systemd[1]: Initializing machine ID from random generator. [ 3.586150] random: systemd: uninitialized urandom read (16 bytes read) [ 3.588781] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.592637] random: systemd: uninitialized urandom read (16 bytes read) [ 3.595173] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.602868] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Apply Kernel Variables... [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Swap. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.265242] device-mapper: uevent: version 1.0.3 [ 4.266776] 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. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 4.999192] virtio_net virtio0 ens2: renamed from eth0 [ 5.050959] random: fast init done [ 5.052648] scsi host0: ata_piix [ 5.058641] scsi host1: ata_piix [ 5.062669] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.066100] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.602331] dracut-initqueue[585]: RTNETLINK answers: File exists [ 9.857967] random: crng init done [ 9.859455] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.328292] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Slices. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.527991] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.799515] SELinux: Disabled at runtime. [ 11.864844] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 11.872688] systemd[1]: Detected virtualization kvm. [ 11.874162] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.381055] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.384861] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.389367] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.393440] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.397091] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.404925] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.413040] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-getty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. Mounting Huge Pages File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Stopped target Switch Root. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Kernel Socket. [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice User and Session Slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Mounting Kernel Debug File System... [ OK ] Listening on Process Core Dump Socket. Activating swap /dev/disk/by-label/SWAP... Starting Apply Kernel Variables... Mounting POSIX Message Queue File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target rpc_pipefs.target. [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK [[ 12.570500] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS 0m] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Stopped target Initrd File Systems. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ 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 Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting 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 ] Mounted /mnt. [ 12.892935] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Coldplug all Devices. [ OK ] Started udev Kernel Device Manager. [ 13.199843] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.215249] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.335844] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.360550] EDAC sbridge: Ver: 1.1.2 [ 14.957477] Key type dns_resolver registered [ 15.253839] NFS: Registering the id_resolver key type [ 15.255414] Key type id_resolver registered [ 15.256971] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg127-server login: [ 41.286776] libcfs: loading out-of-tree module taints kernel. [ 41.301202] Key type ._llcrypt registered [ 41.302827] Key type .llcrypt registered [ 41.357736] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_hostid [ 50.278943] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 51.356372] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 51.365843] alg: No test for adler32 (adler32-zlib) [ 53.171788] Lustre: Lustre: Build Version: 2.17.51_74_g53213db [ 54.336887] LNet: Added LNI 192.168.201.127@tcp [8/256/0/180] [ 56.222504] Key type lgssc registered [ 58.285881] Lustre: Echo OBD driver; http://www.lustre.org/ [ 70.273310] hrtimer: interrupt took 4299912 ns [ 80.652231] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 129.396329] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 143.942356] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 143.962477] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 145.286726] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 145.349136] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 145.476575] Lustre: lustre-MDT0000: new disk, initializing [ 145.615505] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 145.659750] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 150.319330] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 163.961494] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 164.040773] Lustre: 6483:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 164.106899] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 164.118479] Lustre: Skipped 1 previous similar message [ 164.250708] Lustre: lustre-MDT0001: new disk, initializing [ 164.386245] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 164.442763] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 164.470996] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 168.951200] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 174.232443] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 184.276352] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 184.709141] Lustre: lustre-OST0000: new disk, initializing [ 184.718772] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 184.842471] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 186.880779] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 186.895529] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 186.999727] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 191.554150] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 208.496202] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 208.732140] Lustre: lustre-OST0001: new disk, initializing [ 208.737537] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 208.864310] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 216.417647] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 217.127836] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 217.139748] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 217.258235] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 230.843612] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 243.957302] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 255.383505] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing check_logdir /tmp/testlogs/ [ 260.579495] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing yml_node [ 265.683708] Lustre: DEBUG MARKER: Client: 2.17.51.74 [ 268.770349] Lustre: DEBUG MARKER: MDS: 2.17.51.74 [ 271.870353] Lustre: DEBUG MARKER: OSS: 2.17.51.74 [ 273.473256] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Sat Sep 5 05:43:50 EDT 2026 [ 292.374942] Lustre: DEBUG MARKER: excepting tests: [ 302.910596] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 312.800951] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 312.811136] 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 [ 312.833219] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 314.357412] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 314.366759] 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 [ 317.687414] Lustre: server umount lustre-MDT0000 complete [ 324.580254] LustreError: 6490:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 324.626747] LustreError: 6490:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 328.215663] LustreError: 6474:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788601486 with bad export cookie 3473058877960471040 [ 328.223826] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 328.249131] LustreError: 6474:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 328.758773] Lustre: server umount lustre-MDT0001 complete [ 344.993587] Lustre: 3629:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601487/real 1788601487] req@ffff98734299ca80 x1875484304586368/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601503 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 345.032812] 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 [ 345.039848] Lustre: Skipped 2 previous similar messages [ 349.024265] Lustre: 3632:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601491/real 1788601491] req@ffff987472aaf480 x1875484304586624/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601507 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 349.269438] Lustre: server umount lustre-OST0000 complete [ 350.176167] Lustre: 3630:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601492/real 1788601492] req@ffff98734299f480 x1875484304586880/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601508 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 355.233703] Lustre: 3632:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601497/real 1788601497] req@ffff98734266d880 x1875484304587264/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601513 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 360.560581] Lustre: server umount lustre-OST0001 complete [ 378.324768] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing unload_modules_local [ 381.272273] Key type lgssc unregistered [ 381.579077] LNet: 14681:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 381.583872] LNetError: 14681:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 381.598852] LNet: Removed LNI 192.168.201.127@tcp [ 382.555265] Key type .llcrypt unregistered [ 382.556970] Key type ._llcrypt unregistered [ 407.924254] Key type ._llcrypt registered [ 407.928920] Key type .llcrypt registered [ 408.076780] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_hostid [ 422.677872] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 423.989800] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 424.023074] alg: No test for adler32 (adler32-zlib) [ 425.005933] Lustre: Lustre: Build Version: 2.17.51_74_g53213db [ 425.258972] LNet: Added LNI 192.168.201.127@tcp [8/256/0/180] [ 426.944806] Key type lgssc registered [ 428.009320] Lustre: Echo OBD driver; http://www.lustre.org/ [ 482.225424] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 497.797924] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 497.838328] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 499.233393] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 499.273833] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 499.455630] Lustre: lustre-MDT0000: new disk, initializing [ 499.579361] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 499.614295] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 503.426196] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 516.619964] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 516.710901] Lustre: 19088:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 516.734593] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 516.737545] Lustre: Skipped 1 previous similar message [ 516.809918] Lustre: lustre-MDT0001: new disk, initializing [ 516.899513] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 516.937803] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 516.958847] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 520.694756] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 525.360811] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 537.090771] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 537.444837] Lustre: lustre-OST0000: new disk, initializing [ 537.457115] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 537.534024] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 537.747327] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 537.760416] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 537.939087] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 545.157323] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 558.688451] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 558.880774] Lustre: lustre-OST0001: new disk, initializing [ 558.883848] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 558.966082] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 564.719360] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 567.343774] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 567.362396] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 567.441187] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 577.646594] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 586.140049] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 599.692610] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 05:49:16 (1788601756) === [ 601.349380] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 05:49:18 (1788601758) [ 620.353218] Lustre: Failing over lustre-MDT0000 [ 620.719760] Lustre: server umount lustre-MDT0000 complete [ 623.883130] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788601782 with bad export cookie 2170976977854463022 [ 623.884173] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 623.888442] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 623.898406] Lustre: Failing over lustre-MDT0001 [ 624.100265] 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 [ 624.275791] Lustre: server umount lustre-MDT0001 complete [ 632.850555] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 633.952183] LustreError: 23986:0:(import.c:337:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 633.969068] LustreError: 23986:0:(import.c:361:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9873428ad180 x1875484693626240/t0(0) o250->MGC192.168.201.127@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1788601792 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 633.998349] LustreError: 23986:0:(import.c:371:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 634.593577] LustreError: 20988:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 634.607071] LustreError: 20988:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 634.710469] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 634.744577] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 639.433698] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 639.974369] LustreError: 20989:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 643.049344] LustreError: 23999:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 643.076672] LustreError: 23999:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 643.098093] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 648.162875] LustreError: 23998:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 648.199942] LustreError: 23998:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 650.240397] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 650.415561] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 650.555166] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 650.606434] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 650.631911] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 655.843140] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 655.848443] Lustre: Skipped 1 previous similar message [ 655.859341] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 655.876968] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 655.942820] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 655.951910] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 656.240483] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 671.272219] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 05:50:27 (1788601827) [ 694.626813] Lustre: Failing over lustre-MDT0000 [ 694.856261] Lustre: server umount lustre-MDT0000 complete [ 696.810852] 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 [ 696.816222] LustreError: 20989:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 696.827850] Lustre: Skipped 5 previous similar messages [ 696.828427] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 696.877888] LustreError: 20989:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 698.946066] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788601857 with bad export cookie 2170976977854479535 [ 698.949696] Lustre: Failing over lustre-MDT0001 [ 698.949705] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 698.956574] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 699.339275] Lustre: server umount lustre-MDT0001 complete [ 708.056696] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 709.322901] LustreError: 20988:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 709.435978] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 709.470713] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 714.238900] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 714.723138] 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 [ 714.748388] Lustre: Skipped 1 previous similar message [ 717.881750] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 717.891911] Lustre: Skipped 2 previous similar messages [ 718.498364] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601860/real 1788601860] req@ffff987475662680 x1875484693751168/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601876 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 719.904181] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601862/real 1788601862] req@ffff9873428adf80 x1875484693751552/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601878 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 719.930910] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 722.771686] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 722.912748] Lustre: 16267:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601865/real 1788601865] req@ffff9873428af800 x1875484693751936/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601881 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 722.915449] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 722.944224] Lustre: 16267:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 722.966620] Lustre: Skipped 1 previous similar message [ 723.055528] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 723.195218] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 723.197786] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 725.153782] Lustre: 16270:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788601867/real 1788601867] req@ffff9874757de300 x1875484693752320/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788601883 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 725.177295] Lustre: 16270:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 727.279738] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 728.549586] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 728.551611] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 728.576175] Lustre: Skipped 1 previous similar message [ 728.608023] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 728.666081] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 728.667978] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 731.079829] Lustre: *** cfs_fail_loc=193, val=0*** [ 735.441539] Lustre: Failing over lustre-MDT0000 [ 735.652427] Lustre: server umount lustre-MDT0000 complete [ 738.786668] 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 [ 738.790772] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 738.801273] Lustre: Skipped 3 previous similar messages [ 738.804176] LustreError: 24934:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 738.804191] LustreError: 24934:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 744.529153] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 744.629266] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 744.854817] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 744.867428] Lustre: Skipped 1 previous similar message [ 744.893689] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 749.192339] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 750.051121] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 750.062244] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 750.067858] Lustre: Skipped 2 previous similar messages [ 750.082979] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 750.120509] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 750.120563] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 758.707308] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 05:51:55 (1788601915) [ 774.407020] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 791.576295] Lustre: 30192:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 813.047508] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 816.217800] Lustre: 31328:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 840.259787] Lustre: *** cfs_fail_loc=198, val=0*** [ 852.574685] Lustre: Failing over lustre-MDT0000 [ 853.262583] Lustre: server umount lustre-MDT0000 complete [ 857.593996] 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 [ 857.610452] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 857.612853] LustreError: 31345:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 857.612866] LustreError: 31345:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 857.619070] Lustre: Skipped 3 previous similar messages [ 857.725884] LustreError: 19083:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602015 with bad export cookie 2170976977854509124 [ 857.731287] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 857.731634] Lustre: Failing over lustre-MDT0001 [ 857.753512] LustreError: 19083:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 858.357392] Lustre: server umount lustre-MDT0001 complete [ 865.416992] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 872.149552] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 878.057530] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602020/real 1788602020] req@ffff98747e52a300 x1875484693933568/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602036 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 878.059417] 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 [ 878.107367] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 878.151167] Lustre: Skipped 2 previous similar messages [ 881.973400] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 882.275783] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1c921d57 [ 882.284307] Lustre: MGC192.168.201.127@tcp: Connection restored to 0@lo (at 0@lo) [ 882.288560] Lustre: Skipped 3 previous similar messages [ 882.787499] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 882.828618] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 887.254633] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 888.933036] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602031/real 1788602031] req@ffff987341ad8700 x1875484693934080/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602047 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 888.977583] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 897.641280] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 897.962566] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 898.034345] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 898.210443] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:171 to 0x2c0000400:193) [ 898.213043] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 903.468688] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 903.664051] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 903.681213] Lustre: Skipped 2 previous similar messages [ 903.714201] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 903.788581] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 903.793227] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:203 to 0x280000401:225) [ 917.998629] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 05:54:34 (1788602074) [ 941.828973] Lustre: Failing over lustre-MDT0000 [ 942.062850] Lustre: server umount lustre-MDT0000 complete [ 944.612712] 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 [ 944.617905] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 944.631686] Lustre: Skipped 1 previous similar message [ 944.632511] LustreError: 34286:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 944.632519] LustreError: 34286:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 14 previous similar messages [ 946.508305] Lustre: Failing over lustre-MDT0001 [ 946.510068] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602104 with bad export cookie 2170976977854537047 [ 946.513056] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 946.553134] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 946.848193] Lustre: server umount lustre-MDT0001 complete [ 952.066592] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 957.451980] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 965.088499] Lustre: 16270:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602107/real 1788602107] req@ffff987445aed180 x1875484694056064/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602123 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 965.144341] Lustre: 16270:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 966.421376] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 966.482994] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 971.297654] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff987445aef100 x1875484694058368/t0(0) o250->MGC192.168.201.127@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 [ 971.909879] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 976.291711] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 984.035919] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 984.039265] Lustre: Skipped 2 previous similar messages [ 985.331014] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 985.363021] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 985.612590] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 985.819057] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 985.819216] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 990.896159] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 991.222254] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 991.296241] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 991.358354] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 991.359436] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1020.242598] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 1040.708849] Lustre: 38550:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1069.735165] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1074.419799] Lustre: 39688:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1103.448928] Lustre: Failing over lustre-MDT0000 [ 1103.842705] 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 [ 1103.844364] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1103.854301] Lustre: Skipped 4 previous similar messages [ 1103.857586] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1103.872550] Lustre: Skipped 4 previous similar messages [ 1103.986940] Lustre: server umount lustre-MDT0000 complete [ 1108.966691] LustreError: 35645:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1108.997755] LustreError: 35645:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 16 previous similar messages [ 1109.586831] Lustre: Failing over lustre-MDT0001 [ 1109.600160] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602267 with bad export cookie 2170976977854564984 [ 1109.605558] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1109.616630] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1110.471538] Lustre: server umount lustre-MDT0001 complete [ 1117.583400] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1130.468195] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602272/real 1788602272] req@ffff98747f939c00 x1875484694213120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602288 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1130.509760] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1130.618611] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1146.298530] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1146.441463] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1154.099622] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1c92f737 [ 1154.115807] Lustre: MGC192.168.201.127@tcp: Connection restored to 0@lo (at 0@lo) [ 1154.131398] Lustre: Skipped 4 previous similar messages [ 1154.806142] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1154.828162] Lustre: Skipped 3 previous similar messages [ 1154.915663] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1159.744889] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1169.066740] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1169.140838] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1169.581516] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1169.582498] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:298 to 0x280000400:321) [ 1174.502572] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1174.581058] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1174.646046] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 1174.646104] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1174.758442] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1204.273536] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 1226.832978] Lustre: 44359:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1256.187801] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1261.163584] Lustre: 45496:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1298.040498] Lustre: Failing over lustre-MDT0000 [ 1300.380655] Lustre: server umount lustre-MDT0000 complete [ 1302.498199] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1302.512496] LustreError: Skipped 1 previous similar message [ 1302.528440] 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 [ 1302.550472] Lustre: Skipped 8 previous similar messages [ 1305.746562] LustreError: 20030:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602463 with bad export cookie 2170976977854592823 [ 1305.762863] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1305.766207] LustreError: 20030:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1305.776127] Lustre: Failing over lustre-MDT0001 [ 1306.345716] Lustre: server umount lustre-MDT0001 complete [ 1312.158677] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1318.214546] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1322.916603] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602465/real 1788602465] req@ffff987447128000 x1875484694375552/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602481 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1322.935441] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 1329.831060] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1329.891081] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1330.718277] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1335.664599] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1341.924859] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1341.928701] Lustre: Skipped 5 previous similar messages [ 1345.681986] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1345.761493] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1346.324538] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1346.328411] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1351.139120] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1351.655923] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1351.698749] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1351.766428] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1351.774203] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 1368.991333] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 06:02:05 (1788602525) [ 1385.347888] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 1407.813850] Lustre: 50181:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1433.041197] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1472.356646] Lustre: Failing over lustre-MDT0000 [ 1474.557667] 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 [ 1474.574605] LustreError: 24934:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1474.595413] Lustre: Skipped 4 previous similar messages [ 1474.629848] LustreError: 24934:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 27 previous similar messages [ 1474.778867] Lustre: server umount lustre-MDT0000 complete [ 1478.864577] Lustre: Failing over lustre-MDT0001 [ 1478.867066] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602637 with bad export cookie 2170976977854620662 [ 1478.868141] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1478.900040] LustreError: 25500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1479.270851] Lustre: server umount lustre-MDT0001 complete [ 1485.447310] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1495.008856] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602637/real 1788602637] req@ffff98747563df80 x1875484694537600/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602653 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1495.032747] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 1499.547930] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1509.533647] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1521.946593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1534.688897] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1534.731629] Lustre: lustre-MDT0000: reset Object Index mappings [ 1549.855167] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1549.859791] Lustre: Skipped 3 previous similar messages [ 1549.897682] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1554.553536] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1564.856601] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1564.891578] Lustre: lustre-MDT0001: reset Object Index mappings [ 1565.132382] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1565.146769] LustreError: Skipped 2 previous similar messages [ 1565.322305] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:426 to 0x2c0000400:449) [ 1565.334466] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1566.311189] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1566.376070] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1566.456626] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1566.456991] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1570.454812] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1582.937879] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 06:05:39 (1788602739) [ 1609.587135] Lustre: Failing over lustre-MDT0000 [ 1609.988862] Lustre: server umount lustre-MDT0000 complete [ 1613.830892] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602771 with bad export cookie 2170976977854648501 [ 1613.838970] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1613.839860] Lustre: Failing over lustre-MDT0001 [ 1614.058440] Lustre: server umount lustre-MDT0001 complete [ 1619.812747] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1632.441288] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1643.255769] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1654.667837] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1668.816589] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1668.832866] Lustre: lustre-MDT0000: reset Object Index mappings [ 1683.933303] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1688.342914] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1697.409195] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1697.431324] Lustre: lustre-MDT0001: reset Object Index mappings [ 1698.002630] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1698.006879] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1702.171826] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1703.090786] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1703.100950] Lustre: Skipped 9 previous similar messages [ 1703.108744] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1703.139979] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1703.193259] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1703.194144] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1709.822516] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32035: rc = 0 [ 1711.021608] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/96017 with flags 0x52: rc = 0 [ 1733.673838] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 06:08:10 (1788602890) [ 1757.676398] Lustre: Failing over lustre-MDT0000 [ 1758.386987] Lustre: server umount lustre-MDT0000 complete [ 1759.714205] 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 [ 1759.733702] Lustre: Skipped 9 previous similar messages [ 1762.474234] Lustre: Failing over lustre-MDT0001 [ 1762.477154] LustreError: 25498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788602920 with bad export cookie 2170976977854676123 [ 1762.480170] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1762.504850] LustreError: 25498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 1762.823871] Lustre: server umount lustre-MDT0001 complete [ 1769.532181] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1779.846262] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1783.265913] Lustre: 16267:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788602925/real 1788602925] req@ffff98747d1e4380 x1875484694782336/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788602941 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1783.288940] Lustre: 16267:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 1788.602556] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1800.015240] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1811.864971] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1811.895558] Lustre: lustre-MDT0000: reset Object Index mappings [ 1832.497702] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1c94a83b [ 1833.195358] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1837.774573] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1847.774144] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1847.821905] Lustre: lustre-MDT0001: reset Object Index mappings [ 1848.341885] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 1848.358714] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1852.391522] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1852.441691] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1852.508105] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1852.510032] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 1853.897363] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1862.549034] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32009: rc = 0 [ 1864.832539] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/96027 with flags 0x52: rc = 0 [ 1991.020610] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 06:12:27 (1788603147) [ 2024.650157] Lustre: Failing over lustre-MDT0000 [ 2024.858412] Lustre: server umount lustre-MDT0000 complete [ 2026.469989] LustreError: 37391:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2026.493326] LustreError: 37391:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 21 previous similar messages [ 2028.496108] Lustre: Failing over lustre-MDT0001 [ 2028.499590] LustreError: 25498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788603186 with bad export cookie 2170976977854703675 [ 2028.503913] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2028.508344] LustreError: 25498:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2028.835463] Lustre: server umount lustre-MDT0001 complete [ 2034.533106] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2045.868985] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2055.107771] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2065.208661] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2076.239692] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2076.254282] Lustre: lustre-MDT0000: reset Object Index mappings [ 2098.539153] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2098.550953] Lustre: Skipped 5 previous similar messages [ 2098.590684] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2103.066850] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2111.437921] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2111.451563] Lustre: lustre-MDT0001: reset Object Index mappings [ 2111.599354] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2111.609989] LustreError: Skipped 5 previous similar messages [ 2111.774884] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 2111.779112] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 2116.011604] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2117.090904] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2117.165471] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2117.231771] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2117.233606] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 2124.288626] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32008: rc = 0 [ 2127.697504] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 2218.462706] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 06:16:15 (1788603375) [ 2234.962739] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2234.966647] Lustre: Skipped 1 previous similar message [ 2235.469773] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2235.473745] Lustre: Skipped 45 previous similar messages [ 2236.473646] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2236.475454] Lustre: Skipped 241 previous similar messages [ 2254.503717] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 06:16:51 (1788603411) [ 2259.742826] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2259.747271] Lustre: Skipped 167 previous similar messages [ 2272.965950] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 06:17:09 (1788603429) [ 2291.173230] 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 [ 2291.185675] Lustre: Skipped 11 previous similar messages [ 2291.192834] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2292.193134] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2292.203643] Lustre: Skipped 1 previous similar message [ 2295.169037] Lustre: server umount lustre-MDT0000 complete [ 2299.213618] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788603457 with bad export cookie 2170976977854748188 [ 2299.225873] LustreError: 19081:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2302.440547] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2302.450944] Lustre: Skipped 1 previous similar message [ 2304.493880] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2304.498757] Lustre: Skipped 1 previous similar message [ 2305.719779] Lustre: server umount lustre-MDT0001 complete [ 2316.615378] Lustre: server umount lustre-OST0000 complete [ 2326.650689] Lustre: server umount lustre-OST0001 complete [ 2334.352744] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_hostid [ 2341.579707] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 2387.050911] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 2399.738966] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2400.059046] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2400.102684] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2400.186793] Lustre: lustre-MDT0000: new disk, initializing [ 2400.406374] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2406.452494] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2417.787214] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2417.865845] Lustre: 75223:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2417.877204] Lustre: 75223:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 2417.905280] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2417.911468] Lustre: Skipped 1 previous similar message [ 2418.104882] Lustre: lustre-MDT0001: new disk, initializing [ 2418.243749] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2418.255219] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2423.120872] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2427.794331] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2433.701889] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2433.912588] Lustre: lustre-OST0000: new disk, initializing [ 2433.916441] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2435.102963] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2435.119460] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2435.220291] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2438.870717] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2449.432239] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2449.576450] Lustre: lustre-OST0001: new disk, initializing [ 2449.581068] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2451.502143] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2451.508218] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2451.551309] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2455.795387] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2466.655210] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2471.323195] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2498.272582] Lustre: Failing over lustre-MDT0000 [ 2498.516820] Lustre: server umount lustre-MDT0000 complete [ 2503.102719] Lustre: Failing over lustre-MDT0001 [ 2503.528274] Lustre: server umount lustre-MDT0001 complete [ 2510.449670] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2523.104417] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788603665/real 1788603665] req@ffff98734b321880 x1875484695295488/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788603681 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2523.171250] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 2524.373847] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2532.420394] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2542.504970] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2553.161402] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2553.182311] Lustre: lustre-MDT0000: reset Object Index mappings [ 2573.024400] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff98747dec5c00 x1875484695298944/t0(0) o250->MGC192.168.201.127@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 [ 2577.099138] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2585.319585] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2585.666148] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2585.675241] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2589.923225] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2590.723572] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2590.732778] Lustre: Skipped 15 previous similar messages [ 2590.763393] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2590.766588] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2599.580265] Lustre: *** cfs_fail_loc=190, val=3*** [ 2599.580622] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32015: rc = 0 [ 2600.654149] Lustre: *** cfs_fail_loc=190, val=3*** [ 2600.656810] Lustre: Skipped 1 previous similar message [ 2601.683233] Lustre: *** cfs_fail_loc=190, val=3*** [ 2602.865470] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 2604.705555] Lustre: *** cfs_fail_loc=190, val=3*** [ 2604.711067] Lustre: Skipped 2 previous similar messages [ 2608.992322] Lustre: *** cfs_fail_loc=190, val=3*** [ 2608.995844] Lustre: Skipped 2 previous similar messages [ 2615.414509] Lustre: Failing over lustre-MDT0000 [ 2615.792301] Lustre: server umount lustre-MDT0000 complete [ 2620.100048] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2620.111561] Lustre: Failing over lustre-MDT0001 [ 2620.115344] LustreError: Skipped 2 previous similar messages [ 2620.409747] Lustre: server umount lustre-MDT0001 complete [ 2630.943938] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2645.200814] LustreError: 76817:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2645.218383] LustreError: 76817:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 24 previous similar messages [ 2645.352600] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2645.362170] Lustre: Skipped 1 previous similar message [ 2649.892979] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2658.766435] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2659.208365] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2659.212302] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 2663.665686] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2664.444162] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2664.451031] Lustre: Skipped 1 previous similar message [ 2664.466314] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2664.474611] Lustre: Skipped 1 previous similar message [ 2664.515977] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2664.516104] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2670.403235] Lustre: Failing over lustre-MDT0000 [ 2670.589923] Lustre: server umount lustre-MDT0000 complete [ 2675.323580] Lustre: Failing over lustre-MDT0001 [ 2675.683578] Lustre: server umount lustre-MDT0001 complete [ 2687.484715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2687.643200] Lustre: *** cfs_fail_loc=190, val=3*** [ 2687.649512] Lustre: Skipped 2 previous similar messages [ 2700.939737] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2700.942929] Lustre: Skipped 9 previous similar messages [ 2705.824242] Lustre: *** cfs_fail_loc=190, val=3*** [ 2705.833075] Lustre: Skipped 5 previous similar messages [ 2706.304084] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2716.034411] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2716.312118] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2716.317246] LustreError: Skipped 6 previous similar messages [ 2716.461523] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 2716.463166] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2721.485691] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2721.865964] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2721.868149] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2731.425888] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 2731.461395] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x46:0x0]/184: rc = 0 [ 2742.862606] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 06:24:59 (1788603899) [ 2772.288950] Lustre: Failing over lustre-MDT0000 [ 2772.648319] Lustre: server umount lustre-MDT0000 complete [ 2776.501453] Lustre: Failing over lustre-MDT0001 [ 2776.774654] Lustre: server umount lustre-MDT0001 complete [ 2782.296200] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2791.980495] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2800.543054] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2812.698931] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2827.198972] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2827.224422] Lustre: lustre-MDT0000: reset Object Index mappings [ 2827.228097] Lustre: Skipped 1 previous similar message [ 2850.703771] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2858.808521] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2859.162288] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2859.166314] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 2863.418371] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2864.311117] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 2864.311429] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2871.910683] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/64039: rc = 0 [ 2871.920410] Lustre: *** cfs_fail_loc=190, val=2*** [ 2871.948892] Lustre: Skipped 12 previous similar messages [ 2875.234897] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 2888.239103] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x46:0x0]/208: rc = 0 [ 2903.658875] Lustre: Failing over lustre-MDT0000 [ 2903.890070] Lustre: server umount lustre-MDT0000 complete [ 2905.572534] 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 [ 2905.585892] Lustre: Skipped 30 previous similar messages [ 2908.149881] Lustre: Failing over lustre-MDT0001 [ 2908.151590] LustreError: 87228:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788604066 with bad export cookie 2170976977854906983 [ 2908.170504] LustreError: 87228:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 2908.495613] Lustre: server umount lustre-MDT0001 complete [ 2919.519080] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2933.217372] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff987343d30700 x1875484695533824/t0(0) o250->MGC192.168.201.127@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 [ 2937.700746] Lustre: *** cfs_fail_loc=190, val=3*** [ 2937.702964] Lustre: Skipped 30 previous similar messages [ 2937.837911] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2946.260308] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2946.569762] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2946.590816] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 2951.239291] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2951.745778] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 2951.747766] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 2973.093528] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 06:28:49 (1788604129) [ 2990.636534] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 3010.779848] Lustre: 95661:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3033.690353] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3038.072366] Lustre: 96797:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3085.445662] Lustre: Failing over lustre-MDT0000 [ 3087.708425] Lustre: server umount lustre-MDT0000 complete [ 3091.744283] Lustre: Failing over lustre-MDT0001 [ 3092.126335] Lustre: server umount lustre-MDT0001 complete [ 3099.065748] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3110.340368] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3121.774631] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3126.760476] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788604268/real 1788604268] req@ffff98734a5eb480 x1875484695703680/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788604284 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3126.804529] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 69 previous similar messages [ 3135.268085] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3147.466117] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3147.492212] Lustre: lustre-MDT0000: reset Object Index mappings [ 3147.494824] Lustre: Skipped 1 previous similar message [ 3161.633180] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff987342599880 x1875484695705600/t0(0) o250->MGC192.168.201.127@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 [ 3166.654401] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3177.073060] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3177.456024] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 3177.827569] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3177.856865] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 3180.970587] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3180.973945] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 3183.723378] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3193.243912] Lustre: *** cfs_fail_loc=190, val=3*** [ 3193.248992] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32007: rc = 0 [ 3193.252238] Lustre: Skipped 12 previous similar messages [ 3193.309150] Lustre: Skipped 1 previous similar message [ 3196.647789] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32006 with flags 0x52: rc = 0 [ 3218.911518] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 06:32:55 (1788604375) [ 3269.825416] Lustre: Failing over lustre-MDT0000 [ 3270.354455] Lustre: server umount lustre-MDT0000 complete [ 3273.197769] LustreError: 76817:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3273.228935] LustreError: 76817:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 51 previous similar messages [ 3274.421814] Lustre: Failing over lustre-MDT0001 [ 3274.424263] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3274.424272] LustreError: Skipped 4 previous similar messages [ 3274.820624] Lustre: server umount lustre-MDT0001 complete [ 3281.552902] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3292.935569] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3300.478036] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3309.421766] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3321.145847] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3344.675101] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9874771b4e00 x1875484695854720/t0(0) o250->MGC192.168.201.127@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 [ 3345.229767] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3345.232616] Lustre: Skipped 7 previous similar messages [ 3345.289236] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3345.297145] Lustre: Skipped 4 previous similar messages [ 3350.061587] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3359.439786] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3359.790031] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 3359.804224] LustreError: Skipped 6 previous similar messages [ 3360.063830] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 3360.076014] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3364.066328] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3364.083981] Lustre: Skipped 4 previous similar messages [ 3364.091038] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3364.100476] Lustre: Skipped 29 previous similar messages [ 3364.148730] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3364.162362] Lustre: Skipped 4 previous similar messages [ 3364.233022] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 3364.233758] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3365.123693] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3411.226907] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 06:36:07 (1788604567) [ 3426.871515] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 3446.151785] Lustre: 108311:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3470.752323] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3616.341489] Lustre: Failing over lustre-MDT0000 [ 3617.185340] Lustre: server umount lustre-MDT0000 complete [ 3620.327978] 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 [ 3620.355543] Lustre: Skipped 15 previous similar messages [ 3620.825614] LustreError: 87231:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788604778 with bad export cookie 2170976977855050014 [ 3620.837163] LustreError: 87231:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3620.838241] Lustre: Failing over lustre-MDT0001 [ 3621.348982] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3621.361758] Lustre: Skipped 1 previous similar message [ 3621.753540] Lustre: server umount lustre-MDT0001 complete [ 3627.805140] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3641.321374] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3652.785099] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3666.726370] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3684.418619] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3684.460275] Lustre: lustre-MDT0000: reset Object Index mappings [ 3684.466510] Lustre: Skipped 3 previous similar messages [ 3690.914710] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1c9d2766 [ 3696.795529] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3707.423695] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3708.294234] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 3708.329918] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 3710.351170] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3710.353622] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 3714.679222] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3780.265519] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 06:42:17 (1788604937) [ 3797.860503] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 3818.981334] Lustre: 116235:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3818.992966] Lustre: 116235:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 3845.966711] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4018.604490] Lustre: Failing over lustre-MDT0000 [ 4019.256507] Lustre: server umount lustre-MDT0000 complete [ 4020.715543] LustreError: 76816:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4020.763077] LustreError: 76816:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 17 previous similar messages [ 4023.870661] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4023.873662] Lustre: Failing over lustre-MDT0001 [ 4023.879044] LustreError: Skipped 1 previous similar message [ 4024.662450] Lustre: server umount lustre-MDT0001 complete [ 4031.491941] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4041.056197] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788605183/real 1788605183] req@ffff987474fc9c00 x1875484696349696/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788605199 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4041.096640] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 4042.726925] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4052.056194] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4063.705569] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4078.475139] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4094.387814] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1ca7d907 [ 4094.408052] Lustre: MGC192.168.201.127@tcp: Connection restored to 0@lo (at 0@lo) [ 4094.426995] Lustre: Skipped 10 previous similar messages [ 4095.006896] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4095.015156] Lustre: Skipped 3 previous similar messages [ 4095.070708] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4095.088473] Lustre: Skipped 1 previous similar message [ 4100.778728] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4111.763906] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4112.016700] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 4112.032971] LustreError: Skipped 2 previous similar messages [ 4112.157374] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 4112.164502] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 4113.228972] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4113.244852] Lustre: Skipped 1 previous similar message [ 4113.274925] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4113.282094] Lustre: Skipped 1 previous similar message [ 4113.347685] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 4113.350747] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 4117.283963] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4126.576341] Lustre: *** cfs_fail_loc=190, val=1*** [ 4126.578332] Lustre: Skipped 49 previous similar messages [ 4126.580055] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64003: rc = 0 [ 4129.883687] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 4137.389778] Lustre: Failing over lustre-MDT0000 [ 4139.752433] Lustre: server umount lustre-MDT0000 complete [ 4143.801683] Lustre: Failing over lustre-MDT0001 [ 4144.117061] Lustre: server umount lustre-MDT0001 complete [ 4153.302679] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4168.675859] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1e20dc0f1ca7dff9 [ 4173.791809] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4183.524787] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4184.012416] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 4184.012913] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 4188.683776] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4189.267275] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 4189.268466] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 4195.272898] Lustre: Failing over lustre-MDT0000 [ 4195.712283] Lustre: server umount lustre-MDT0000 complete [ 4200.249206] Lustre: Failing over lustre-MDT0001 [ 4200.804581] Lustre: server umount lustre-MDT0001 complete [ 4211.419617] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4211.606288] Lustre: *** cfs_fail_loc=190, val=1*** [ 4211.608473] Lustre: Skipped 27 previous similar messages [ 4229.834799] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4239.090248] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4239.596798] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 4239.613728] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 4240.640559] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:545) [ 4240.651638] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 4244.829336] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4260.812526] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 06:50:17 (1788605417) [ 4275.194456] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 4292.441152] Lustre: 127163:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4292.451100] Lustre: 127163:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 4317.297069] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4355.929807] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 06:51:52 (1788605512) [ 4361.967644] Lustre: *** cfs_fail_loc=195, val=0*** [ 4362.570581] Lustre: *** cfs_fail_loc=195, val=0*** [ 4362.576887] Lustre: Skipped 31 previous similar messages [ 4367.630898] Lustre: Failing over lustre-OST0000 [ 4367.790610] Lustre: server umount lustre-OST0000 complete [ 4368.869238] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4368.892536] Lustre: Skipped 22 previous similar messages [ 4378.596336] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4385.876397] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4582.725544] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 06:55:39 (1788605739) [ 4587.286655] Lustre: *** cfs_fail_loc=196, val=0*** [ 4587.290383] Lustre: Skipped 31 previous similar messages [ 4594.233478] Lustre: Failing over lustre-OST0000 [ 4594.321418] Lustre: server umount lustre-OST0000 complete [ 4604.225326] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4611.284368] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4802.494500] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 06:59:19 (1788605959) [ 4809.419194] Lustre: *** cfs_fail_loc=196, val=0*** [ 4809.421142] Lustre: Skipped 63 previous similar messages [ 4813.691307] Lustre: *** cfs_fail_loc=196, val=0*** [ 4813.694604] Lustre: Skipped 415 previous similar messages [ 4828.445785] Lustre: Failing over lustre-OST0000 [ 4828.573756] Lustre: server umount lustre-OST0000 complete [ 4829.672250] LustreError: 76807:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4829.691470] LustreError: 76807:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 40 previous similar messages [ 4841.171475] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4841.440373] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4841.460825] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4841.467447] Lustre: Skipped 4 previous similar messages [ 4842.726566] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4842.740851] Lustre: Skipped 4 previous similar messages [ 4842.802237] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4842.806756] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4842.814636] Lustre: Skipped 4 previous similar messages [ 4842.835737] Lustre: Skipped 20 previous similar messages [ 4848.156881] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4861.931849] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4861.935693] Lustre: Skipped 3 previous similar messages [ 4862.315375] Lustre: server umount lustre-MDT0000 complete [ 4867.364438] LustreError: 75216:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788606025 with bad export cookie 2170976977855964760 [ 4867.365092] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4867.369849] LustreError: 75216:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 12 previous similar messages [ 4867.382358] LustreError: Skipped 2 previous similar messages [ 4867.646269] Lustre: server umount lustre-MDT0001 complete [ 4881.582471] Lustre: server umount lustre-OST0000 complete [ 4895.730400] Lustre: server umount lustre-OST0001 complete [ 4906.968240] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 07:01:04 (1788606064) [ 4925.203908] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_hostid [ 4936.692768] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 4989.084561] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 4999.344927] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4999.607807] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4999.636445] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4999.732585] Lustre: lustre-MDT0000: new disk, initializing [ 4999.861666] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4999.864549] Lustre: Skipped 7 previous similar messages [ 4999.896662] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5004.671531] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5015.248278] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5015.327975] Lustre: 138421:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 5015.342394] Lustre: 138421:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 5015.390334] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5015.395508] Lustre: Skipped 1 previous similar message [ 5015.501685] Lustre: lustre-MDT0001: new disk, initializing [ 5015.635818] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5015.648800] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5020.600719] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5025.563599] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5032.679589] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5032.882697] Lustre: lustre-OST0000: new disk, initializing [ 5032.886404] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5034.463086] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5034.473886] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5034.529110] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5039.032305] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5048.833650] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5048.951757] Lustre: lustre-OST0001: new disk, initializing [ 5048.961573] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5050.287224] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5050.300815] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5050.365979] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5054.862396] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5064.653863] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5068.327686] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5093.134437] Lustre: Failing over lustre-MDT0000 [ 5093.465713] Lustre: server umount lustre-MDT0000 complete [ 5096.418268] 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 [ 5096.435871] Lustre: Skipped 12 previous similar messages [ 5097.286530] LustreError: 138413:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788606255 with bad export cookie 2170976977856083753 [ 5097.288633] Lustre: Failing over lustre-MDT0001 [ 5097.304122] LustreError: 138413:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5097.548833] Lustre: server umount lustre-MDT0001 complete [ 5103.283416] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5114.259401] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5116.897594] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788606259/real 1788606259] req@ffff98746b0b0700 x1875484696963584/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788606275 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5116.918768] Lustre: 16269:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 35 previous similar messages [ 5123.842726] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5135.937633] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5148.714405] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5148.738071] Lustre: lustre-MDT0000: reset Object Index mappings [ 5148.741218] Lustre: Skipped 3 previous similar messages [ 5167.202156] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff98746b08f800 x1875484696967552/t0(0) o250->MGC192.168.201.127@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 [ 5171.973354] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5181.580303] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5181.760826] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5181.766757] LustreError: Skipped 7 previous similar messages [ 5181.918893] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 5181.919432] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 5186.051323] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 5186.052143] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 5186.259409] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5241.100793] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 07:06:37 (1788606397) [ 5256.254722] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 5303.949469] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5342.249019] Lustre: Failing over lustre-MDT0000 [ 5342.288047] Lustre: *** cfs_fail_loc=199, val=0*** [ 5342.300463] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5342.317699] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5342.340951] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5342.360980] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5342.371573] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5342.383490] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5342.397367] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5342.417892] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5342.437809] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5342.452786] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5342.466066] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5342.477154] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5342.507063] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5342.528419] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5342.538118] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5342.550413] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5342.571642] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5342.590803] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5342.605979] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5342.626585] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5342.641577] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5342.662731] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5342.674107] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5342.685980] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5342.704561] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5342.716965] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5342.735645] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5342.754800] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5342.774810] Lustre: *** cfs_fail_loc=199, val=0*** [ 5342.783924] Lustre: Skipped 27 previous similar messages [ 5342.786649] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5342.796782] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5342.809172] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5342.835345] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5342.852920] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5342.865854] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5342.885340] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5342.901442] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5342.916298] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5342.931294] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5342.948780] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5342.965831] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5342.974078] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5342.985248] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5343.007470] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5343.044092] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5343.072852] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5343.092464] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5343.106688] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5343.128244] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5343.143556] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5343.155981] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5343.178077] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5343.205947] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5343.216480] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5343.225820] Lustre: 150562:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5343.733819] Lustre: server umount lustre-MDT0000 complete [ 5348.475157] Lustre: Failing over lustre-MDT0001 [ 5348.476235] LustreError: 138414:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788606506 with bad export cookie 2170976977856100658 [ 5348.505239] Lustre: *** cfs_fail_loc=199, val=0*** [ 5348.526586] LustreError: 138414:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 5348.533973] Lustre: Skipped 25 previous similar messages [ 5348.534160] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5348.540974] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5348.585344] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5348.600940] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5348.618741] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5348.642418] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5348.655341] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5348.665664] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5348.680925] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5348.698208] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5348.719941] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5348.737549] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5348.755662] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5348.768336] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5348.777875] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5348.789481] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5348.798724] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5348.823326] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5348.835380] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5348.846607] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5348.856293] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5348.864268] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5348.872236] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5348.880150] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5348.888601] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5348.920383] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5348.929458] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5348.949366] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5348.961787] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5348.980325] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5349.006304] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5349.016719] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5349.026468] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5349.042092] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5349.052723] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5349.062150] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5349.076293] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5349.089304] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5349.102358] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5349.117428] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5349.133904] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5349.148416] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5349.161761] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5349.176352] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5349.190702] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5349.205316] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5349.218763] Lustre: 150763:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5349.501373] Lustre: server umount lustre-MDT0001 complete [ 5361.377675] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5361.553068] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5361.565756] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5361.585250] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5361.609186] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5361.632323] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5361.659974] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5361.677913] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5361.692801] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5361.711244] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5361.734053] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5361.744165] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5361.757625] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5361.772229] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5361.785937] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5361.803390] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5361.827866] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5361.849636] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5361.863421] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5361.885562] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5361.905256] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5361.927104] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5361.942312] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5361.953587] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5361.969980] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5361.986980] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5361.995466] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5362.007743] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5362.024921] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5362.043769] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5362.054791] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5362.065731] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5362.075791] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5362.093978] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5362.111554] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5362.123470] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5362.136682] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5362.161531] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5362.183130] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5362.203888] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5362.216824] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5362.246868] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5362.264456] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5362.277724] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5362.295903] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5362.324820] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5362.343177] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5362.358731] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5362.377233] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5362.395185] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5362.409647] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5362.425731] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5362.439760] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5362.454320] Lustre: 151261:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5378.910518] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5388.210179] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5388.460420] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5388.486989] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5388.518302] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5388.552883] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5388.569647] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5388.580477] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5388.589774] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5388.598503] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5388.621805] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5388.644815] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5388.661496] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5388.680501] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5388.706327] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5388.722660] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5388.744556] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5388.764695] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5388.783757] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5388.805564] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5388.835767] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5388.853140] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5388.874565] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5388.888811] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5388.907252] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5388.919708] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5388.930942] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5388.948925] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5388.969880] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5388.987708] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5389.009540] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5389.019894] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5389.036218] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5389.050746] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5389.070566] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5389.093471] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5389.126089] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5389.131729] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5389.138633] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5389.166180] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5389.192813] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5389.219747] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5389.232761] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5389.244597] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5389.252385] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5389.259699] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5389.268431] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5389.277321] Lustre: 151993:0:(osd_scrub.c:1829:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5389.552614] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 5389.562970] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 5394.470559] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5395.024946] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5395.035026] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 5406.121830] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 07:09:22 (1788606562) [ 5407.305522] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5407.313176] Lustre: Skipped 123 previous similar messages [ 5409.205507] Lustre: Failing over lustre-MDT0000 [ 5409.503400] Lustre: server umount lustre-MDT0000 complete [ 5428.976438] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5431.787740] LustreError: 145151:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5431.812102] LustreError: 145151:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 57 previous similar messages [ 5440.919590] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5441.584759] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5441.584830] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 5445.095856] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 07:10:01 (1788606601) [ 5446.278318] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5448.469952] Lustre: Failing over lustre-MDT0000 [ 5448.925576] Lustre: server umount lustre-MDT0000 complete [ 5468.129171] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5468.137602] LustreError: Skipped 3 previous similar messages [ 5468.165251] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5478.369910] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff98747f794380 x1875484697209600/t0(0) o250->MGC192.168.201.127@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 [ 5478.737056] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5478.754268] Lustre: Skipped 3 previous similar messages [ 5479.108832] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5479.120810] Lustre: Skipped 3 previous similar messages [ 5483.631942] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5484.016816] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5484.029092] Lustre: Skipped 15 previous similar messages [ 5484.065063] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 5484.077737] Lustre: Skipped 3 previous similar messages [ 5484.119614] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5484.120252] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 5487.952581] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 07:10:44 (1788606644) [ 5512.393365] Lustre: Failing over lustre-MDT0000 [ 5512.720675] Lustre: server umount lustre-MDT0000 complete [ 5516.966711] Lustre: Failing over lustre-MDT0001 [ 5517.461864] Lustre: server umount lustre-MDT0001 complete [ 5528.904789] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5542.432859] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff987342a4ea00 x1875484697324160/t0(0) o250->MGC192.168.201.127@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5549.943352] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5560.048796] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5560.401109] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 5560.414236] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5564.681957] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5565.494349] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 5565.494739] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5572.468622] Lustre: Failing over lustre-MDT0000 [ 5572.781529] Lustre: server umount lustre-MDT0000 complete [ 5576.657668] Lustre: Failing over lustre-MDT0001 [ 5576.985592] Lustre: server umount lustre-MDT0001 complete [ 5586.384830] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5586.418979] Lustre: lustre-MDT0000: reset Object Index mappings [ 5586.423800] Lustre: Skipped 1 previous similar message [ 5601.796266] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5601.801722] Lustre: Skipped 11 previous similar messages [ 5607.317220] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5616.708765] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5617.206687] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 5617.219516] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5621.523666] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5622.351670] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 5622.352343] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5632.945172] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 07:13:09 (1788606789) [ 5640.228223] LustreError: 150351:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff98734b055c00 x1875484697403264/t0(0) o104->lustre-OST0001@192.168.201.27@tcp:15/16 lens 328/224 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'' uid:4294967295 gid:4294967295 projid:4294967295 [ 5640.269922] LustreError: 150344:0:(ldlm_lock.c:2770:ldlm_lock_dump_handle()) ### ### ns: filter-lustre-OST0000_UUID lock: 0000000027fbb1cb/0x1e20dc0f1cab1bc0 lrc: 4/0,0 mode: PR/PR res: [0x280000400:0x96:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400010020 nid: 192.168.201.27@tcp remote: 0x7c039faf67c324e1 expref: 28 pid: 150352 timeout: 5740 lvb_type: 1 lru_score: 0 lru_type: 0 [ 5642.726468] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5642.732537] Lustre: Skipped 3 previous similar messages [ 5647.846854] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5647.860822] Lustre: Skipped 3 previous similar messages [ 5648.818650] Lustre: server umount lustre-MDT0000 complete [ 5652.916703] LustreError: 150339:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788606811 with bad export cookie 2170976977856163294 [ 5652.929288] LustreError: 150339:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 5652.975857] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5652.985217] Lustre: Skipped 1 previous similar message [ 5653.436993] Lustre: server umount lustre-MDT0001 complete [ 5660.682769] Lustre: server umount lustre-OST0000 complete [ 5664.726071] Lustre: server umount lustre-OST0001 complete [ 5671.378672] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5680.938901] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5696.481796] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5701.600414] LustreError: 160674:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.127@tcp: failed processing log, type 4: rc = -110 [ 5735.116558] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5740.560901] Lustre: Failing over lustre-OST0000 [ 5740.805609] Lustre: server umount lustre-OST0000 complete [ 5747.194837] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5756.391026] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5771.937957] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5777.057909] LustreError: 162184:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.127@tcp: failed processing log, type 4: rc = -110 [ 5809.047975] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5819.052219] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 07:16:15 (1788606975) [ 5834.369983] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 5845.783609] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5846.417958] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5850.994341] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5859.745117] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5860.144694] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5864.538554] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5867.597320] Lustre: 165024:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5867.606431] Lustre: 165024:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 2 previous similar messages [ 5882.279617] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5883.868425] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 5883.878891] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 5888.824261] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5897.543192] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5908.557388] Lustre: *** cfs_fail_loc=193, val=0*** [ 5910.247175] Lustre: Failing over lustre-MDT0000 [ 5910.463975] Lustre: server umount lustre-MDT0000 complete [ 5911.522556] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5911.534493] LustreError: Skipped 7 previous similar messages [ 5911.541839] 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 [ 5911.558414] Lustre: Skipped 34 previous similar messages [ 5920.545553] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5920.890571] Lustre: *** cfs_fail_loc=193, val=0*** [ 5920.892812] Lustre: Skipped 1 previous similar message [ 5926.472994] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 5926.478697] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5926.544585] Lustre: *** cfs_fail_loc=193, val=0*** [ 5926.549119] Lustre: Skipped 3 previous similar messages [ 5927.515674] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5932.523610] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5932.523633] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5932.537708] Lustre: Skipped 48 previous similar messages [ 5939.661330] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5939.667173] Lustre: Skipped 3 previous similar messages [ 5948.915926] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 07:18:25 (1788607105) [ 5952.259845] Lustre: Failing over lustre-MDT0000 [ 5952.436674] Lustre: server umount lustre-MDT0000 complete [ 5956.724767] Lustre: Failing over lustre-MDT0001 [ 5957.130935] Lustre: server umount lustre-MDT0001 complete [ 5960.242556] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5968.295715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5973.475428] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788607115/real 1788607115] req@ffff987342a4d180 x1875484697514112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788607131 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5973.521807] Lustre: 16268:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 49 previous similar messages [ 5981.728623] LustreError: 16266:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff987475657480 x1875484697516672/t0(0) o250->MGC192.168.201.127@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 [ 5982.098945] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000400:0x1:0x0]/74 with flags 0x4a: rc = 0 [ 5982.105153] Lustre: 168785:0:(lod_sub_object.c:941:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't open llog [0x200000400:0x1:0x0]: rc = -115 [ 5982.114220] LustreError: 168785:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osd: get update log duration 0, retries 0, failed: rc = -115 [ 5986.486458] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5995.211322] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5999.472824] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6000.676326] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000401:0x1:0x0]/76 with flags 0x4a: rc = 0 [ 6001.669807] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 6001.674886] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 6001.751058] LustreError: 169495:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 6001.840949] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 6001.848277] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 6005.633799] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 6013.008684] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 07:19:29 (1788607169) [ 6016.994407] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6021.089852] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6022.828471] Lustre: server umount lustre-MDT0000 complete [ 6026.968869] Lustre: server umount lustre-MDT0001 complete [ 6041.673107] Lustre: server umount lustre-OST0000 complete [ 6056.460548] Lustre: server umount lustre-OST0001 complete [ 6066.014167] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6080.612417] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6081.156852] LustreError: 171823:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6081.190496] LustreError: 171823:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 118 previous similar messages [ 6086.469326] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6092.943454] Lustre: Failing over lustre-MDT0000 [ 6092.953945] LustreError: 171856:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6092.963315] LustreError: 171856:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6092.968712] LustreError: 171856:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 12, retries 0, failed: rc = -5 [ 6093.334839] Lustre: server umount lustre-MDT0000 complete [ 6100.552230] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6116.056563] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6122.019070] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6133.161080] Lustre: DEBUG MARKER: === sanity-scrub: start setup 07:21:29 (1788607289) === [ 6136.723349] LustreError: 173475:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6136.731414] LustreError: 173475:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6136.737097] LustreError: 173475:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 19, retries 0, failed: rc = -5 [ 6137.086987] Lustre: server umount lustre-MDT0000 complete [ 6174.439461] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_hostid [ 6182.310419] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 6234.242216] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing load_modules_local [ 6247.803724] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6248.060530] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6248.106491] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6248.289837] Lustre: lustre-MDT0000: new disk, initializing [ 6248.402488] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6248.412041] Lustre: Skipped 11 previous similar messages [ 6248.455326] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6253.613215] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6269.893648] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6270.121385] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6270.124591] Lustre: Skipped 1 previous similar message [ 6270.229564] Lustre: lustre-MDT0001: new disk, initializing [ 6270.368176] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6270.378352] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6275.869836] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6281.016533] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6291.495938] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6291.738707] Lustre: lustre-OST0000: new disk, initializing [ 6291.742306] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6293.813612] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6293.831308] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6293.908331] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6299.230669] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6314.764322] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6314.901299] Lustre: lustre-OST0001: new disk, initializing [ 6314.906614] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6316.064945] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6316.070573] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6316.183064] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6321.275862] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6331.394412] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6335.416117] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6346.375187] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 07:25:03 (1788607503) === [ 6348.069697] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 6073 sec ========= 07:25:04 (1788607504) [ 6350.505465] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 07:25:06 (1788607506) === [ 6354.518583] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 07:25:11 (1788607511) === [ 6362.606225] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6362.620618] Lustre: Skipped 6 previous similar messages [ 6366.317979] Lustre: server umount lustre-MDT0000 complete [ 6375.094659] LustreError: 178762:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788607533 with bad export cookie 2170976977856190013 [ 6375.109994] LustreError: MGC192.168.201.127@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6375.117853] LustreError: 178762:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 6375.149918] LustreError: Skipped 6 previous similar messages [ 6375.756741] Lustre: server umount lustre-MDT0001 complete [ 6396.525631] Lustre: server umount lustre-OST0000 complete [ 6404.879737] Lustre: server umount lustre-OST0001 complete [ 6424.426580] Lustre: DEBUG MARKER: oleg127-server.virtnet: executing unload_modules_local [ 6427.800927] Key type lgssc unregistered [ 6428.281705] LNet: 185060:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6428.293842] LNetError: 185060:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6428.314285] LNet: Removed LNI 192.168.201.127@tcp [ 6429.424152] Key type .llcrypt unregistered [ 6429.429166] Key type ._llcrypt unregistered