[ 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 492529490 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 0x1465a2000-0x1465ccfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002394] x2apic enabled [ 0.003008] Switched APIC routing to physical x2apic. [ 0.004013] kvm-guest: setup PV IPIs [ 0.007422] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008022] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009013] pid_max: default: 32768 minimum: 301 [ 0.010136] LSM: Security Framework initializing [ 0.011049] Yama: becoming mindful. [ 0.012037] SELinux: Initializing. [ 0.014019] *** VALIDATE selinux *** [ 0.022256] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027255] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028128] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029104] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030105] *** VALIDATE tmpfs *** [ 0.031471] *** VALIDATE proc *** [ 0.032256] *** VALIDATE cgroup *** [ 0.033025] *** VALIDATE cgroup2 *** [ 0.034267] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035162] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036007] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037032] Spectre V2 : User space: Vulnerable [ 0.038011] Speculative Store Bypass: Vulnerable [ 0.041293] debug: unmapping init [mem 0xffffffff8dc59000-0xffffffff8dc60fff] [ 0.043169] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044721] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045031] ... version: 2 [ 0.046016] ... bit width: 48 [ 0.047016] ... generic registers: 4 [ 0.048012] ... value mask: 0000ffffffffffff [ 0.049015] ... max period: 00007fffffffffff [ 0.050013] ... fixed-purpose events: 3 [ 0.051012] ... event mask: 000000070000000f [ 0.052311] rcu: Hierarchical SRCU implementation. [ 0.054374] smp: Bringing up secondary CPUs ... [ 0.055692] x86: Booting SMP configuration: [ 0.056032] .... node #0, CPUs: #1 #2 #3 [ 0.059636] smp: Brought up 1 node, 4 CPUs [ 0.061012] smpboot: Max logical packages: 1 [ 0.062016] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.141517] node 0 deferred pages initialised in 75ms [ 0.144167] devtmpfs: initialized [ 0.145241] x86/mm: Memory block size: 128MB [ 0.147780] gcov: version magic: 0x41383552 [ 0.149352] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.153119] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.155302] pinctrl core: initialized pinctrl subsystem [ 0.157164] [ 0.157654] ************************************************************* [ 0.161014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.163012] ** ** [ 0.166009] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.169026] ** ** [ 0.171010] ** This means that this kernel is built to expose internal ** [ 0.175013] ** IOMMU data structures, which may compromise security on ** [ 0.178012] ** your system. ** [ 0.182013] ** ** [ 0.183010] ** If you see this message and you are not debugging the ** [ 0.186020] ** kernel, report this immediately to your vendor! ** [ 0.189014] ** ** [ 0.192014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.195013] ************************************************************* [ 0.197681] NET: Registered protocol family 16 [ 0.199419] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.202054] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.205081] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.209095] cpuidle: using governor menu [ 0.210640] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.213544] PCI: Using configuration type 1 for base access [ 0.216130] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.225140] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.228021] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.232017] cryptd: max_cpu_qlen set to 1000 [ 0.235147] ACPI: Added _OSI(Module Device) [ 0.236020] ACPI: Added _OSI(Processor Device) [ 0.237015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.239011] ACPI: Added _OSI(Processor Aggregator Device) [ 0.244344] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.250533] ACPI: Interpreter enabled [ 0.252070] ACPI: PM: (supports S0 S3 S4 S5) [ 0.253011] ACPI: Using IOAPIC for interrupt routing [ 0.255105] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.258418] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.268678] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.271047] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.274021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.278114] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.282159] acpiphp: Slot [2] registered [ 0.283123] acpiphp: Slot [5] registered [ 0.284109] acpiphp: Slot [6] registered [ 0.286097] acpiphp: Slot [7] registered [ 0.287107] acpiphp: Slot [8] registered [ 0.289118] acpiphp: Slot [9] registered [ 0.290136] acpiphp: Slot [10] registered [ 0.292122] acpiphp: Slot [3] registered [ 0.293106] acpiphp: Slot [4] registered [ 0.295099] acpiphp: Slot [11] registered [ 0.296099] acpiphp: Slot [12] registered [ 0.297000] acpiphp: Slot [13] registered [ 0.297000] acpiphp: Slot [14] registered [ 0.299097] acpiphp: Slot [15] registered [ 0.301110] acpiphp: Slot [16] registered [ 0.303101] acpiphp: Slot [17] registered [ 0.304107] acpiphp: Slot [18] registered [ 0.306105] acpiphp: Slot [19] registered [ 0.307121] acpiphp: Slot [20] registered [ 0.309133] acpiphp: Slot [21] registered [ 0.311076] acpiphp: Slot [22] registered [ 0.313091] acpiphp: Slot [23] registered [ 0.313844] acpiphp: Slot [24] registered [ 0.315100] acpiphp: Slot [25] registered [ 0.316210] acpiphp: Slot [26] registered [ 0.317000] acpiphp: Slot [27] registered [ 0.319173] acpiphp: Slot [28] registered [ 0.320127] acpiphp: Slot [29] registered [ 0.322352] acpiphp: Slot [30] registered [ 0.324149] acpiphp: Slot [31] registered [ 0.325111] PCI host bridge to bus 0000:00 [ 0.326029] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.329039] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.332035] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.334035] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.337038] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.339041] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.340227] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.343372] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.346491] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.355015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.359988] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.361016] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.363015] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.364013] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.366618] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.369875] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.372046] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.375117] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.382019] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.396887] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.401790] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.407969] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.418017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.425017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.443016] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.456063] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.465018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.472020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.493000] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.501853] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.510014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.521016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.545026] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.559782] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.573015] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.584017] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.603015] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.614063] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.629017] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.637015] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.665031] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.689211] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.700017] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.713018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.749020] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.767057] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.768285] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.770302] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.771269] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.774188] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.777217] iommu: Default domain type: Passthrough [ 0.779453] SCSI subsystem initialized [ 0.781152] ACPI: bus type USB registered [ 0.782097] usbcore: registered new interface driver usbfs [ 0.784127] usbcore: registered new interface driver hub [ 0.786090] usbcore: registered new device driver usb [ 0.787176] pps_core: LinuxPPS API ver. 1 registered [ 0.788012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.792066] PTP clock support registered [ 0.795066] EDAC MC: Ver: 3.0.0 [ 0.797147] PCI: Using ACPI for IRQ routing [ 0.798858] NetLabel: Initializing [ 0.800010] NetLabel: domain hash size = 128 [ 0.801010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.802081] NetLabel: unlabeled traffic allowed by default [ 0.805053] vgaarb: loaded [ 0.807292] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.809015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.820467] clocksource: Switched to clocksource kvm-clock [ 0.928632] VFS: Disk quotas dquot_6.6.0 [ 0.930890] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.934121] *** VALIDATE ramfs *** [ 0.935393] *** VALIDATE hugetlbfs *** [ 0.936890] pnp: PnP ACPI init [ 0.939269] pnp: PnP ACPI: found 6 devices [ 0.962084] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.965776] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.968516] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.971175] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.974053] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.976768] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.980297] NET: Registered protocol family 2 [ 0.983399] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.988724] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.993355] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.999451] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.003608] TCP: Hash tables configured (established 65536 bind 65536) [ 1.006729] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.010397] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.013468] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.016971] NET: Registered protocol family 1 [ 1.021283] RPC: Registered named UNIX socket transport module. [ 1.023423] RPC: Registered udp transport module. [ 1.025352] RPC: Registered tcp transport module. [ 1.027386] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.030254] NET: Registered protocol family 44 [ 1.033111] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.037162] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.038870] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.040978] PCI: CLS 0 bytes, default 64 [ 1.042246] Unpacking initramfs... [ 2.452251] debug: unmapping init [mem 0xffff8a7f7cc54000-0xffff8a7f7ffbffff] [ 2.456244] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.458664] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.461522] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.965361] Initialise system trusted keyrings [ 2.967396] Key type blacklist registered [ 2.969416] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.982210] zbud: loaded [ 2.986401] *** VALIDATE nfs *** [ 2.987822] *** VALIDATE nfs4 *** [ 2.989598] pstore: using deflate compression [ 2.993186] Platform Keyring initialized [ 3.124535] NET: Registered protocol family 38 [ 3.126695] Key type asymmetric registered [ 3.128501] Asymmetric key parser 'x509' registered [ 3.130548] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.135686] io scheduler mq-deadline registered [ 3.137549] io scheduler kyber registered [ 3.138751] io scheduler bfq registered [ 3.140860] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.145549] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.148645] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.151560] ACPI: Power Button [PWRF] [ 3.157340] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.164235] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.188918] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.203050] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.233110] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.264455] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.292484] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.298200] Non-volatile memory driver v1.3 [ 3.300249] Linux agpgart interface v0.103 [ 3.340602] virtio_blk virtio1: [vda] 146728 512-byte logical blocks (75.1 MB/71.6 MiB) [ 3.345201] vda: detected capacity change from 0 to 75124736 [ 3.366126] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.369329] vdb: detected capacity change from 0 to 1073741824 [ 3.391031] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.394304] vdc: detected capacity change from 0 to 2621440000 [ 3.414279] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.418315] vdd: detected capacity change from 0 to 2621440000 [ 3.445760] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.451151] vde: detected capacity change from 0 to 4294967296 [ 3.474064] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.476649] vdf: detected capacity change from 0 to 4294967296 [ 3.486202] libphy: Fixed MDIO Bus: probed [ 3.493923] usbcore: registered new interface driver usbserial_generic [ 3.496936] usbserial: USB Serial support registered for generic [ 3.499928] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.504882] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.506911] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.509855] mousedev: PS/2 mouse device common for all mice [ 3.513224] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.514559] rtc_cmos 00:05: RTC can wake from S4 [ 3.522444] rtc_cmos 00:05: registered as rtc0 [ 3.522475] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.524234] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.530147] intel_pstate: CPU model not supported [ 3.532585] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.536329] hid: raw HID events driver (C) Jiri Kosina [ 3.538830] usbcore: registered new interface driver usbhid [ 3.540718] usbhid: USB HID core driver [ 3.542343] drop_monitor: Initializing network drop monitor service [ 3.544604] Initializing XFRM netlink socket [ 3.546451] NET: Registered protocol family 10 [ 3.549810] Segment Routing with IPv6 [ 3.551555] NET: Registered protocol family 17 [ 3.553938] mpls_gso: MPLS GSO support [ 3.560485] RAS: Correctable Errors collector initialized. [ 3.563105] AVX version of gcm_enc/dec engaged. [ 3.564820] AES CTR mode by8 optimization enabled [ 3.674663] sched_clock: Marking stable (3674637440, 0)->(4620461977, -945824537) [ 3.679127] registered taskstats version 1 [ 3.681348] Loading compiled-in X.509 certificates [ 3.683345] zswap: loaded using pool lzo/zbud [ 3.711786] Key type big_key registered [ 3.726255] Key type encrypted registered [ 3.728388] ima: No TPM chip found, activating TPM-bypass! [ 3.731141] ima: Allocated hash algorithm: sha1 [ 3.733548] ima: No architecture policies found [ 3.735698] evm: Initialising EVM extended attributes: [ 3.737365] evm: security.selinux [ 3.738335] evm: security.ima [ 3.739275] evm: security.capability [ 3.740750] evm: HMAC attrs: 0x1 [ 3.743739] rtc_cmos 00:05: setting system clock to 2026-09-08 03:11:43 UTC (1788837103) [ 3.750551] debug: unmapping init [mem 0xffffffff8ec03000-0xffffffff8edfffff] [ 3.753569] debug: unmapping init [mem 0xffffffff8d982000-0xffffffff8dc58fff] [ 3.757074] Write protecting the kernel read-only data: 28672k [ 3.760757] debug: unmapping init [mem 0xffffffff8c003000-0xffffffff8c1fffff] [ 3.763899] debug: unmapping init [mem 0xffffffff8c914000-0xffffffff8c9fffff] [ 3.801870] 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.810361] systemd[1]: Detected virtualization kvm. [ 3.812412] systemd[1]: Detected architecture x86-64. [ 3.814642] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.840847] systemd[1]: No hostname configured. [ 3.842779] systemd[1]: Set hostname to . [ 3.844818] random: systemd: uninitialized urandom read (16 bytes read) [ 3.847363] systemd[1]: Initializing machine ID from random generator. [ 3.898690] random: ln: uninitialized urandom read (6 bytes read) [ 3.992552] random: systemd: uninitialized urandom read (16 bytes read) [ 3.994921] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.999815] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 4.004237] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Slices. [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket. Starting Create list of required st…ce nodes for the current kernel... Starting Journal Service... [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Reached target Timers. [ OK ] Started Memstrack Anylazing Service. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Initrd Root Device. Starting Apply Kernel Variables... Starting Create Volatile Files and Directories... [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.728085] device-mapper: uevent: version 1.0.3 [ 4.730618] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.482325] random: fast init done [ 5.500674] virtio_net virtio0 ens2: renamed from eth0 [ 5.565458] scsi host0: ata_piix [ 5.570079] scsi host1: ata_piix [ 5.602395] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.607868] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.449821] dracut-initqueue[585]: RTNETLINK answers: File exists [ 10.249684] random: crng init done [ 10.250859] 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.816235] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local File Systems. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.063878] printk: systemd: 25 output lines suppressed due to ratelimiting [ 12.349203] SELinux: Disabled at runtime. [ 12.415395] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.426203] systemd[1]: Detected virtualization kvm. [ 12.428179] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.026344] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.030217] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.035444] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.042388] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.047143] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.057241] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.086108] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on initctl Compatibility Named Pipe. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Switch Root. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on RPCbind Server Activation Socket. Starting Apply Kernel Variables... Mounting Kernel Debug File System... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Stopped target Initrd File Systems. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Stopped target Initrd Root File System. Starting Remount Root and Kernel File Systems... Mounting POSIX Message Queue File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target RPC Port Mapper. Mounting Huge Pages File System... [ OK ] Created slice User and Session Slice. [ OK ] Reached target S[ 13.257736] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS lices. [ OK ] Reached target rpc_pipefs.target. [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages 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. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.596283] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.910173] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.959742] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 14.063796] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.087768] EDAC sbridge: Ver: 1.1.2 [ 15.855452] Key type dns_resolver registered [ 16.184444] NFS: Registering the id_resolver key type [ 16.186732] Key type id_resolver registered [ 16.188650] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started RPC Bind. [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started dnf makecache --timer. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Login Service. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ 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 System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. 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 oleg453-server login: [ 78.455169] libcfs: loading out-of-tree module taints kernel. [ 78.523458] Key type ._llcrypt registered [ 78.527149] Key type .llcrypt registered [ 78.646463] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_hostid [ 98.780773] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 100.332338] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 100.345157] alg: No test for adler32 (adler32-zlib) [ 101.820188] Lustre: Lustre: Build Version: 2.17.57_113_gf5ca795 [ 102.700503] LNet: Added LNI 192.168.204.153@tcp [8/256/0/180] [ 104.543165] Key type lgssc registered [ 106.558591] Lustre: Echo OBD driver; http://www.lustre.org/ [ 126.834031] hrtimer: interrupt took 5948601 ns [ 126.917199] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 169.713033] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 184.260362] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 184.288686] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 185.594651] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 185.642817] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 185.805740] Lustre: lustre-MDT0000: new disk, initializing [ 185.884615] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 185.902781] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 190.479611] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 203.459388] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 203.601729] Lustre: 6516:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 203.632573] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 203.640278] Lustre: Skipped 1 previous similar message [ 203.751715] Lustre: lustre-MDT0001: new disk, initializing [ 203.831614] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 203.855116] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 203.864813] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 208.987300] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 213.663225] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 222.394980] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 222.588416] Lustre: lustre-OST0000: new disk, initializing [ 222.593771] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 222.600751] Lustre: 8454:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 222.677358] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 228.225673] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 230.454902] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 230.475538] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 230.526147] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 243.006564] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 243.158453] Lustre: lustre-OST0001: new disk, initializing [ 243.160985] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 243.165916] Lustre: 9527:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 243.221478] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 249.928733] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 252.463451] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 252.472669] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 252.526582] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 262.460553] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 269.644543] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 276.592719] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing check_logdir /tmp/testlogs/ [ 282.348386] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing yml_node [ 286.933978] Lustre: DEBUG MARKER: Client: 2.17.57.113 [ 290.014556] Lustre: DEBUG MARKER: MDS: 2.17.57.113 [ 292.980660] Lustre: DEBUG MARKER: OSS: 2.17.57.113 [ 294.828295] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Mon Sep 7 23:16:31 EDT 2026 [ 313.753274] Lustre: DEBUG MARKER: excepting tests: [ 325.306453] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 334.305891] 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 [ 334.309520] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 334.335912] Lustre: Skipped 1 previous similar message [ 334.360409] Lustre: Skipped 3 previous similar messages [ 339.425141] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 339.437233] Lustre: Skipped 3 previous similar messages [ 340.350729] Lustre: server umount lustre-MDT0000 complete [ 349.667359] LustreError: 6528:0:(ldlm_lib.c:1190: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. [ 349.683440] LustreError: 6528:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 8 previous similar messages [ 349.743972] LustreError: 6509:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788837449 with bad export cookie 3105484571845367171 [ 349.750589] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 349.753567] LustreError: 6509:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 350.148749] Lustre: server umount lustre-MDT0001 complete [ 369.645313] Lustre: server umount lustre-OST0000 complete [ 370.655141] Lustre: 3649:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837454/real 1788837454] req@ffff8a7ffc66c380 x1875731758030464/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837470 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 370.711958] 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 [ 370.735430] Lustre: Skipped 2 previous similar messages [ 375.264058] Lustre: 3647:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837459/real 1788837459] req@ffff8a7ff1455f80 x1875731758030720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837475 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 376.800535] Lustre: 3648:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837460/real 1788837460] req@ffff8a7fdd1a5880 x1875731758030976/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837476 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 378.268792] Lustre: server umount lustre-OST0001 complete [ 396.167532] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing unload_modules_local [ 399.046299] Key type lgssc unregistered [ 399.333238] LNet: 14799:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 399.346192] LNetError: 14799:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 399.363902] LNet: Removed LNI 192.168.204.153@tcp [ 400.294157] Key type .llcrypt unregistered [ 400.296649] Key type ._llcrypt unregistered [ 424.011743] Key type ._llcrypt registered [ 424.014540] Key type .llcrypt registered [ 424.117493] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_hostid [ 438.983922] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 439.945939] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 439.961678] alg: No test for adler32 (adler32-zlib) [ 440.967182] Lustre: Lustre: Build Version: 2.17.57_113_gf5ca795 [ 441.313382] LNet: Added LNI 192.168.204.153@tcp [8/256/0/180] [ 443.015157] Key type lgssc registered [ 444.005650] Lustre: Echo OBD driver; http://www.lustre.org/ [ 498.758476] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 512.929944] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 512.967524] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 514.295242] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 514.334819] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 514.409637] Lustre: lustre-MDT0000: new disk, initializing [ 514.502273] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 514.539267] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 519.382341] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 533.361319] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 533.470471] Lustre: 19260:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 533.497236] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 533.502510] Lustre: Skipped 1 previous similar message [ 533.631264] Lustre: lustre-MDT0001: new disk, initializing [ 533.763086] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 533.807855] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 533.824843] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 538.822329] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 543.701562] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 554.418948] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 554.850980] Lustre: lustre-OST0000: new disk, initializing [ 554.864844] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 554.887980] Lustre: 21198:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 554.999071] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 557.943901] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 557.951719] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 558.111123] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 562.368159] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 575.479505] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 575.627599] Lustre: lustre-OST0001: new disk, initializing [ 575.632682] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 575.639063] Lustre: 22221:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 575.703062] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 582.201825] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 582.212602] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 582.291205] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 582.326980] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 593.669044] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 601.150228] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 610.099430] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 23:21:46 (1788837706) === [ 611.904447] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 23:21:49 (1788837709) [ 633.977241] Lustre: Failing over lustre-MDT0000 [ 634.357564] Lustre: server umount lustre-MDT0000 complete [ 636.385580] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 636.393943] 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 [ 638.438987] 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 [ 638.473458] Lustre: Skipped 2 previous similar messages [ 638.967113] LustreError: 20674:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788837738 with bad export cookie 14670059931970023490 [ 638.968213] Lustre: Failing over lustre-MDT0001 [ 638.975076] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 638.996585] LustreError: 20674:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 639.518228] Lustre: server umount lustre-MDT0001 complete [ 649.172826] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 659.936910] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837743/real 1788837743] req@ffff8a7ec55b6d80 x1875732113526272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837759 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 659.989325] 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 [ 664.326085] LustreError: 21192:0:(ldlm_lib.c:1190: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. [ 664.345249] LustreError: 21192:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 6 previous similar messages [ 664.429397] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 664.476600] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 665.055206] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837748/real 1788837748] req@ffff8a7ec55b6a00 x1875732113526528/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837764 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 665.112196] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 665.443612] LustreError: 21193:0:(ldlm_lib.c:1190: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. [ 669.535776] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837753/real 1788837753] req@ffff8a7eca5edf80 x1875732113526912/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837769 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 669.553966] LustreError: 24240:0:(ldlm_lib.c:1190: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. [ 669.567988] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 669.598721] LustreError: 24240:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 670.097951] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 674.595992] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837758/real 1788837758] req@ffff8a7eca5eca80 x1875732113527040/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837774 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 674.621922] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 674.791779] LustreError: 24240:0:(ldlm_lib.c:1190: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. [ 674.810162] LustreError: 24240:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 678.741891] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 678.893722] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 678.894531] LustreError: 21192:0:(ldlm_lib.c:1190: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. [ 678.943525] LustreError: 21192:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 679.153423] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 679.268332] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 679.336504] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 679.342233] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 684.265291] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 684.521564] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 684.526328] Lustre: Skipped 1 previous similar message [ 684.529203] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 684.566780] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 684.656257] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 684.656423] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 697.566331] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 23:23:14 (1788837794) [ 719.136295] Lustre: Failing over lustre-MDT0000 [ 719.430338] Lustre: server umount lustre-MDT0000 complete [ 720.357529] 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 [ 720.372310] Lustre: Skipped 3 previous similar messages [ 720.374489] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 720.384439] LustreError: 21192:0:(ldlm_lib.c:1190: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. [ 723.647592] Lustre: Failing over lustre-MDT0001 [ 723.649464] LustreError: 19250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788837823 with bad export cookie 14670059931970039800 [ 723.670749] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 723.696553] LustreError: 19250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 723.998239] Lustre: server umount lustre-MDT0001 complete [ 733.414026] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 733.957241] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 733.996581] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 739.301466] 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 [ 739.308141] LustreError: 21193:0:(ldlm_lib.c:1190: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. [ 739.322036] Lustre: Skipped 1 previous similar message [ 739.334690] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 739.339096] LustreError: 21193:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 6 previous similar messages [ 740.399476] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 740.404732] Lustre: Skipped 2 previous similar messages [ 741.408123] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837825/real 1788837825] req@ffff8a7ff48cce00 x1875732113640704/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837841 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 741.430969] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 748.993676] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 749.217482] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 749.381728] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 749.384794] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 750.367197] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837833/real 1788837833] req@ffff8a7ec273aa00 x1875732113641600/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837849 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 750.407269] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 754.663159] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 754.665726] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 754.677342] Lustre: Skipped 1 previous similar message [ 754.712971] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 754.772480] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 754.772971] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 754.862517] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 759.089092] Lustre: *** cfs_fail_loc=193, val=0*** [ 764.300572] Lustre: Failing over lustre-MDT0000 [ 764.565367] Lustre: server umount lustre-MDT0000 complete [ 764.905964] 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 [ 764.921048] Lustre: Skipped 3 previous similar messages [ 764.925432] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 773.654357] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 773.850411] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 774.119844] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 774.127266] Lustre: Skipped 1 previous similar message [ 774.173892] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 779.157786] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 779.236572] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 779.248143] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 779.254210] Lustre: Skipped 2 previous similar messages [ 779.276609] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 779.340268] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 779.347535] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 788.601961] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 23:24:45 (1788837885) [ 801.655293] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 822.267171] Lustre: 30512:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 844.674578] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 848.387163] Lustre: 31647:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 862.046425] Lustre: *** cfs_fail_loc=198, val=0*** [ 872.290375] Lustre: Failing over lustre-MDT0000 [ 872.568383] Lustre: server umount lustre-MDT0000 complete [ 876.101738] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788837975 with bad export cookie 14670059931970068654 [ 876.111174] Lustre: Failing over lustre-MDT0001 [ 876.114529] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 876.118731] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 876.604857] Lustre: server umount lustre-MDT0001 complete [ 881.930150] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 886.915421] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 892.896345] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788837976/real 1788837976] req@ffff8a7ec32e8a80 x1875732113802240/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788837992 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 892.896465] 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 [ 892.932628] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 892.989599] Lustre: Skipped 4 previous similar messages [ 895.810532] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 901.217924] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866c4c9a7 [ 901.229423] Lustre: MGC192.168.204.153@tcp: Connection restored to 0@lo (at 0@lo) [ 901.248352] Lustre: Skipped 3 previous similar messages [ 901.517223] LustreError: 25257:0:(ldlm_lib.c:1190: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. [ 901.538222] LustreError: 25257:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 14 previous similar messages [ 901.588996] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 901.651805] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 906.064074] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 914.614994] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 914.937903] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 915.090710] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 915.140501] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 915.158117] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 919.047833] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 920.553851] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 920.566855] Lustre: Skipped 2 previous similar messages [ 920.599329] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 920.670084] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 920.672785] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 931.820170] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 23:27:08 (1788838028) [ 953.399566] Lustre: Failing over lustre-MDT0000 [ 953.617916] Lustre: server umount lustre-MDT0000 complete [ 956.390521] 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 [ 956.392675] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 957.319357] LustreError: 20674:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838057 with bad export cookie 14670059931970095527 [ 957.324882] Lustre: Failing over lustre-MDT0001 [ 957.326350] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 957.344366] LustreError: 20674:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 957.795801] Lustre: server umount lustre-MDT0001 complete [ 962.873536] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 967.603675] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 977.858850] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 977.887729] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788838061/real 1788838061] req@ffff8a7ec32ead80 x1875732113924224/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788838077 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 977.945759] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 977.997526] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 983.135641] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7eca778700 x1875732113926656/t0(0) o250->MGC192.168.204.153@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 983.459875] LustreError: 21192:0:(ldlm_lib.c:1190: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. [ 983.479798] LustreError: 21192:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 13 previous similar messages [ 983.579605] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 987.127609] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 995.026910] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 995.061804] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 995.322244] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 995.462271] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 995.480987] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:233 to 0x2c0000400:257) [ 996.454749] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 996.460972] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 996.473346] Lustre: Skipped 2 previous similar messages [ 996.514729] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 996.568905] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 996.571866] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 999.846635] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1024.067920] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 1042.831727] Lustre: 38950:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1067.509364] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1070.821038] Lustre: 40088:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1092.404876] Lustre: Failing over lustre-MDT0000 [ 1092.696150] Lustre: server umount lustre-MDT0000 complete [ 1094.123239] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1094.131947] 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 [ 1094.140828] Lustre: Skipped 5 previous similar messages [ 1096.523357] LustreError: 25754:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838196 with bad export cookie 14670059931970123177 [ 1096.527522] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1096.530809] Lustre: Failing over lustre-MDT0001 [ 1096.536676] LustreError: 25754:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1096.871541] Lustre: server umount lustre-MDT0001 complete [ 1101.426922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1110.030566] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1112.336356] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788838196/real 1788838196] req@ffff8a7ffc19c000 x1875732114065792/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788838212 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1112.368832] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 1122.595299] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1122.630566] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1142.007790] LustreError: 21193:0:(ldlm_lib.c:1190: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. [ 1142.038053] LustreError: 21193:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 7 previous similar messages [ 1142.146421] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1142.153151] Lustre: Skipped 3 previous similar messages [ 1142.191391] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1147.275774] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1156.999958] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1157.061705] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1157.549183] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1157.554502] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1158.518232] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1158.524921] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1158.526980] Lustre: Skipped 4 previous similar messages [ 1158.587677] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1158.645605] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 1158.649195] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 1162.548345] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1186.358321] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 1203.019949] Lustre: 44797:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1225.362537] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1228.824318] Lustre: 45932:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1249.923065] Lustre: Failing over lustre-MDT0000 [ 1250.122331] Lustre: server umount lustre-MDT0000 complete [ 1250.786391] 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 [ 1250.794915] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1250.809025] Lustre: Skipped 5 previous similar messages [ 1250.834848] LustreError: Skipped 1 previous similar message [ 1253.480471] Lustre: Failing over lustre-MDT0001 [ 1253.483055] LustreError: 19250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838353 with bad export cookie 14670059931970150330 [ 1253.483608] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1253.503211] LustreError: 19250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1253.708916] Lustre: server umount lustre-MDT0001 complete [ 1258.110630] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1265.512945] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1272.032111] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788838355/real 1788838355] req@ffff8a7ff6b87800 x1875732114205056/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788838371 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1272.051424] Lustre: 16420:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 16 previous similar messages [ 1276.791926] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1276.833809] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1278.941907] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1283.550687] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1291.255559] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1291.263113] Lustre: Skipped 4 previous similar messages [ 1291.920156] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1291.965646] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1292.381689] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:361 to 0x280000400:385) [ 1292.384625] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1297.243178] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1297.379372] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1297.428952] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1297.476949] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 1297.478332] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1317.263190] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 23:33:33 (1788838413) [ 1332.383120] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 1350.442484] Lustre: 50641:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1374.777173] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1398.633764] Lustre: Failing over lustre-MDT0000 [ 1398.960797] Lustre: server umount lustre-MDT0000 complete [ 1399.776821] LustreError: 21193:0:(ldlm_lib.c:1190: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. [ 1399.805671] LustreError: 21193:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 20 previous similar messages [ 1402.536996] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838502 with bad export cookie 14670059931970177483 [ 1402.549172] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1402.549404] Lustre: Failing over lustre-MDT0001 [ 1402.553430] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1402.997900] Lustre: server umount lustre-MDT0001 complete [ 1410.098970] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1420.725417] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1429.671413] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1440.384967] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1452.195780] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1452.215975] Lustre: lustre-MDT0000: reset Object Index mappings [ 1472.481428] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866c673dc [ 1473.104481] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1473.111400] Lustre: Skipped 3 previous similar messages [ 1473.155102] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1477.942963] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1486.951573] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1486.984124] Lustre: lustre-MDT0001: reset Object Index mappings [ 1487.466753] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 1487.467533] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1490.472967] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1490.523163] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1490.578499] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1490.578499] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 1491.626762] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1502.254246] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 23:36:39 (1788838599) [ 1526.469334] Lustre: Failing over lustre-MDT0000 [ 1526.755737] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1526.765143] LustreError: Skipped 3 previous similar messages [ 1526.767453] 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 [ 1526.774088] Lustre: Skipped 10 previous similar messages [ 1526.810583] Lustre: server umount lustre-MDT0000 complete [ 1530.170923] Lustre: Failing over lustre-MDT0001 [ 1530.173604] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838629 with bad export cookie 14670059931970204636 [ 1530.178964] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1530.198997] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1530.594266] Lustre: server umount lustre-MDT0001 complete [ 1536.046048] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1545.749059] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1548.257792] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788838632/real 1788838632] req@ffff8a7ff5b78380 x1875732114470016/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788838648 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1548.285798] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 1554.060721] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1565.282107] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1577.525503] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1577.542641] Lustre: lustre-MDT0000: reset Object Index mappings [ 1599.875799] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1604.232041] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1612.033989] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1612.058466] Lustre: lustre-MDT0001: reset Object Index mappings [ 1612.429192] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:489 to 0x2c0000400:513) [ 1612.435439] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1616.300777] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1617.910467] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1617.944630] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1617.945551] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1617.955858] Lustre: Skipped 10 previous similar messages [ 1617.990942] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:521 to 0x280000401:545) [ 1617.996408] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1624.324296] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/96025: rc = 0 [ 1625.488671] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 1648.348647] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 23:39:05 (1788838745) [ 1669.808215] Lustre: Failing over lustre-MDT0000 [ 1670.018264] Lustre: server umount lustre-MDT0000 complete [ 1673.384260] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788838773 with bad export cookie 14670059931970232048 [ 1673.386776] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1673.388337] Lustre: Failing over lustre-MDT0001 [ 1673.394585] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1673.682592] Lustre: server umount lustre-MDT0001 complete [ 1678.962174] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1688.759886] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1698.037732] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1708.900495] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1719.920342] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1719.940294] Lustre: lustre-MDT0000: reset Object Index mappings [ 1745.592933] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1750.528817] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1758.528137] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1758.549517] Lustre: lustre-MDT0001: reset Object Index mappings [ 1758.909570] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1758.931822] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1761.959393] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1762.001694] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1762.042228] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:585 to 0x280000401:609) [ 1762.052374] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1763.295436] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1771.288452] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32011: rc = 0 [ 1774.564339] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 1891.112157] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 23:43:08 (1788838988) [ 1923.620509] Lustre: Failing over lustre-MDT0000 [ 1923.887527] Lustre: server umount lustre-MDT0000 complete [ 1926.113176] LustreError: 21193:0:(ldlm_lib.c:1190: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. [ 1926.139339] LustreError: 21193:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 19 previous similar messages [ 1927.745744] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788839027 with bad export cookie 14670059931970259572 [ 1927.747462] Lustre: Failing over lustre-MDT0001 [ 1927.753540] LustreError: 19251:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1928.083350] Lustre: server umount lustre-MDT0001 complete [ 1934.188973] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1943.413205] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1951.526972] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1960.962700] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1973.131397] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1973.144697] Lustre: lustre-MDT0000: reset Object Index mappings [ 1997.996636] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1998.002881] Lustre: Skipped 5 previous similar messages [ 2003.146736] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2012.034280] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2012.054369] Lustre: lustre-MDT0001: reset Object Index mappings [ 2012.381441] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 2012.388451] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:617 to 0x280000400:641) [ 2016.629571] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2017.613084] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 2017.616280] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 2024.607451] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/64001: rc = 0 [ 2027.922124] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 2112.493819] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 23:46:49 (1788839209) [ 2129.661325] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2129.668049] Lustre: Skipped 1 previous similar message [ 2130.165568] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2130.172398] Lustre: Skipped 21 previous similar messages [ 2131.180192] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2131.183149] Lustre: Skipped 201 previous similar messages [ 2153.237617] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 23:47:30 (1788839250) [ 2157.803532] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2157.811020] Lustre: Skipped 231 previous similar messages [ 2158.085605] LustreError: 21184:0:(osd_compat.c:737:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 264/4001468694 265/3044646948 [ 2170.998190] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 23:47:47 (1788839267) [ 2186.738541] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2186.750872] LustreError: Skipped 4 previous similar messages [ 2186.758625] 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 [ 2186.787390] Lustre: Skipped 17 previous similar messages [ 2186.809413] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2188.781908] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2188.794871] Lustre: Skipped 1 previous similar message [ 2192.685308] Lustre: server umount lustre-MDT0000 complete [ 2196.539669] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788839296 with bad export cookie 14670059931970303742 [ 2196.541072] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2196.546625] LustreError: 19252:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2196.552100] LustreError: Skipped 1 previous similar message [ 2199.012138] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2199.019106] Lustre: Skipped 3 previous similar messages [ 2201.057205] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2201.071745] Lustre: Skipped 1 previous similar message [ 2203.043682] Lustre: server umount lustre-MDT0001 complete [ 2213.259401] Lustre: server umount lustre-OST0000 complete [ 2231.263418] Lustre: lustre-OST0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2231.566223] Lustre: server umount lustre-OST0001 complete [ 2238.476268] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_hostid [ 2245.872984] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 2287.575108] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 2297.971518] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2298.148370] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2298.167176] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2298.226314] Lustre: lustre-MDT0000: new disk, initializing [ 2298.326358] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2302.388108] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2314.779222] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2314.951298] Lustre: 75840:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2314.970478] Lustre: 75840:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2315.031519] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2315.046489] Lustre: Skipped 1 previous similar message [ 2315.133338] Lustre: lustre-MDT0001: new disk, initializing [ 2315.279210] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2315.292167] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2321.427802] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2326.912812] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2334.013633] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2334.427260] Lustre: lustre-OST0000: new disk, initializing [ 2334.432712] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2334.441857] Lustre: 77472:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2336.096319] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2336.108492] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2336.204761] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2341.801664] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2352.901625] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2353.022255] Lustre: lustre-OST0001: new disk, initializing [ 2353.027764] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2353.034690] Lustre: 78343:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2354.186633] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2354.203551] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2354.252878] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2359.079812] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2368.101460] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2370.963936] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2389.911604] Lustre: Failing over lustre-MDT0000 [ 2389.990659] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2389.998730] Lustre: Skipped 3 previous similar messages [ 2390.180784] Lustre: server umount lustre-MDT0000 complete [ 2393.461741] Lustre: Failing over lustre-MDT0001 [ 2393.792359] Lustre: server umount lustre-MDT0001 complete [ 2399.619415] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2409.028235] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2410.404946] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788839494/real 1788839494] req@ffff8a7ec55e8700 x1875732115109888/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788839510 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2410.445525] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 32 previous similar messages [ 2416.031925] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2425.667379] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2436.066872] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2436.110813] Lustre: lustre-MDT0000: reset Object Index mappings [ 2440.160431] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7ffdab0000 x1875732115112704/t0(0) o250->MGC192.168.204.153@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 [ 2440.724392] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2440.737996] Lustre: Skipped 1 previous similar message [ 2444.914699] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2454.679940] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2455.009783] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2455.019442] Lustre: Skipped 1 previous similar message [ 2455.123765] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2455.126878] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 2456.113038] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2456.131029] Lustre: Skipped 14 previous similar messages [ 2456.163300] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2456.171105] Lustre: Skipped 1 previous similar message [ 2456.221716] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 2456.234516] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2460.081344] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2470.704705] Lustre: *** cfs_fail_loc=190, val=3*** [ 2470.705714] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32027: rc = 0 [ 2471.759132] Lustre: *** cfs_fail_loc=190, val=3*** [ 2471.765327] Lustre: Skipped 1 previous similar message [ 2472.796126] Lustre: *** cfs_fail_loc=190, val=3*** [ 2474.004776] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32001 with flags 0x52: rc = 0 [ 2475.807230] Lustre: *** cfs_fail_loc=190, val=3*** [ 2475.810527] Lustre: Skipped 2 previous similar messages [ 2480.163237] Lustre: *** cfs_fail_loc=190, val=3*** [ 2480.165535] Lustre: Skipped 2 previous similar messages [ 2486.735877] Lustre: Failing over lustre-MDT0000 [ 2487.018856] Lustre: server umount lustre-MDT0000 complete [ 2490.887288] Lustre: Failing over lustre-MDT0001 [ 2491.337438] Lustre: server umount lustre-MDT0001 complete [ 2503.005489] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2521.037757] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2527.200507] LustreError: 84114:0:(ldlm_lib.c:1190: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. [ 2527.213445] LustreError: 84114:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 31 previous similar messages [ 2529.830308] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2530.219929] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2530.223260] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:97) [ 2531.267478] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:97) [ 2531.268321] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2534.370524] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2539.759566] Lustre: Failing over lustre-MDT0000 [ 2540.082543] Lustre: server umount lustre-MDT0000 complete [ 2544.230650] Lustre: Failing over lustre-MDT0001 [ 2544.601525] Lustre: server umount lustre-MDT0001 complete [ 2554.827717] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2554.996468] Lustre: *** cfs_fail_loc=190, val=3*** [ 2555.000552] Lustre: Skipped 2 previous similar messages [ 2573.087222] Lustre: *** cfs_fail_loc=190, val=3*** [ 2573.097385] Lustre: Skipped 5 previous similar messages [ 2574.015990] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2582.471975] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2582.947285] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2582.963058] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:129) [ 2587.364229] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2588.220531] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2588.224228] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:129) [ 2599.265718] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32001 with flags 0x52: rc = 0 [ 2599.303934] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/161: rc = 0 [ 2611.032194] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 23:55:08 (1788839708) [ 2636.749058] Lustre: Failing over lustre-MDT0000 [ 2637.503770] Lustre: server umount lustre-MDT0000 complete [ 2641.381951] Lustre: Failing over lustre-MDT0001 [ 2641.751447] Lustre: server umount lustre-MDT0001 complete [ 2647.440773] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2658.195650] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2666.777168] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2677.059180] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2690.005368] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2690.040260] Lustre: lustre-MDT0000: reset Object Index mappings [ 2690.043647] Lustre: Skipped 1 previous similar message [ 2712.031679] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7ff7fb2d80 x1875732115303040/t0(0) o250->MGC192.168.204.153@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 [ 2712.609605] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2712.621843] Lustre: Skipped 11 previous similar messages [ 2717.276489] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2726.358693] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2726.738685] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 2726.742473] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 2729.844979] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 2729.848931] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2731.492354] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2739.380768] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32002: rc = 0 [ 2739.392899] Lustre: *** cfs_fail_loc=190, val=2*** [ 2739.402957] Lustre: Skipped 12 previous similar messages [ 2742.721862] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32022 with flags 0x52: rc = 0 [ 2755.757952] Lustre: lustre-MDT0001: trigger partial OI scrub for RPC inconsistency, checking FID [0x240001b71:0x44:0x0]/235: rc = 0 [ 2755.771245] Lustre: Skipped 1 previous similar message [ 2768.613809] Lustre: Failing over lustre-MDT0000 [ 2769.013100] Lustre: server umount lustre-MDT0000 complete [ 2773.098859] Lustre: Failing over lustre-MDT0001 [ 2773.106418] LustreError: 76634:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788839872 with bad export cookie 14670059931970461718 [ 2773.121713] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2773.125291] LustreError: 76634:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 15 previous similar messages [ 2773.140456] LustreError: Skipped 4 previous similar messages [ 2773.485624] Lustre: server umount lustre-MDT0001 complete [ 2782.691419] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2783.207379] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866ca6786 [ 2788.022658] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2788.833661] 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 [ 2788.846811] Lustre: Skipped 33 previous similar messages [ 2796.682512] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2796.903484] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2796.920869] LustreError: Skipped 8 previous similar messages [ 2797.043140] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 2797.057172] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 2800.623855] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2802.237570] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:225) [ 2802.238969] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 2804.002898] Lustre: *** cfs_fail_loc=190, val=3*** [ 2804.007097] Lustre: Skipped 33 previous similar messages [ 2818.721280] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 23:58:35 (1788839915) [ 2832.538594] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 2850.032390] Lustre: 96521:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2873.797111] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2877.688603] Lustre: 97657:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2914.587274] Lustre: Failing over lustre-MDT0000 [ 2914.894329] Lustre: server umount lustre-MDT0000 complete [ 2918.759796] Lustre: Failing over lustre-MDT0001 [ 2919.262642] Lustre: server umount lustre-MDT0001 complete [ 2924.734173] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2934.339327] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2943.271437] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2953.605718] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2965.193188] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2965.238107] Lustre: lustre-MDT0000: reset Object Index mappings [ 2965.243551] Lustre: Skipped 1 previous similar message [ 2988.511598] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7ecb1e5180 x1875732115500672/t0(0) o250->MGC192.168.204.153@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 [ 2988.831600] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2988.835422] Lustre: Skipped 4 previous similar messages [ 2993.819827] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3003.187283] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3003.522926] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3003.528651] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 3004.519915] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3004.541022] Lustre: Skipped 4 previous similar messages [ 3004.566913] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3004.580682] Lustre: Skipped 4 previous similar messages [ 3004.631321] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3004.631375] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 3007.922422] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3016.451904] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32005: rc = 0 [ 3016.453130] Lustre: *** cfs_fail_loc=190, val=3*** [ 3016.464939] Lustre: Skipped 1 previous similar message [ 3018.657646] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/96021 with flags 0x52: rc = 0 [ 3038.158156] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 00:02:15 (1788840135) [ 3082.449374] Lustre: Failing over lustre-MDT0000 [ 3082.852769] Lustre: server umount lustre-MDT0000 complete [ 3086.303377] Lustre: Failing over lustre-MDT0001 [ 3086.833266] Lustre: server umount lustre-MDT0001 complete [ 3092.164421] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3101.941644] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3104.230738] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788840187/real 1788840187] req@ffff8a7fdc224a80 x1875732115635968/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788840203 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3104.284468] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 62 previous similar messages [ 3111.184439] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3121.000119] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3133.387626] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3156.514968] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866cc8ac8 [ 3156.532346] Lustre: MGC192.168.204.153@tcp: Connection restored to 0@lo (at 0@lo) [ 3156.553411] Lustre: Skipped 30 previous similar messages [ 3156.864319] LustreError: 77465:0:(ldlm_lib.c:1190: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. [ 3156.877548] LustreError: 77465:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 45 previous similar messages [ 3162.027556] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3170.841827] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3171.298468] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:329 to 0x2c0000400:353) [ 3171.306264] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3172.355554] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3172.355891] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 3176.590707] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3212.622223] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 00:05:09 (1788840309) [ 3225.726261] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 3242.229866] Lustre: 109187:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3264.576423] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3398.020064] Lustre: Failing over lustre-MDT0000 [ 3398.781767] Lustre: server umount lustre-MDT0000 complete [ 3399.658060] 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 [ 3399.695307] Lustre: Skipped 15 previous similar messages [ 3402.907943] LustreError: 88039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788840502 with bad export cookie 14670059931970603720 [ 3402.909553] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3402.923061] LustreError: 88039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3402.937564] LustreError: Skipped 2 previous similar messages [ 3402.967119] Lustre: Failing over lustre-MDT0001 [ 3403.541782] Lustre: server umount lustre-MDT0001 complete [ 3409.591978] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3422.068363] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3435.074493] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3449.584249] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3464.275298] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3472.351593] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7ffbaedc00 x1875732115856896/t0(0) o250->MGC192.168.204.153@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 [ 3472.713206] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3472.725306] Lustre: Skipped 7 previous similar messages [ 3477.956807] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3487.492065] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3487.546818] Lustre: lustre-MDT0001: reset Object Index mappings [ 3487.555136] Lustre: Skipped 4 previous similar messages [ 3487.921796] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 3487.929367] LustreError: Skipped 2 previous similar messages [ 3488.072201] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:393 to 0x2c0000400:417) [ 3488.084535] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 3490.198078] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3490.207293] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 3493.540315] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3562.338335] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 00:10:59 (1788840659) [ 3577.277911] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 3594.804644] Lustre: 117149:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3594.816493] Lustre: 117149:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 3618.446881] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3801.612990] Lustre: Failing over lustre-MDT0000 [ 3802.597504] LustreError: 77466:0:(ldlm_lib.c:1190: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. [ 3802.621490] LustreError: 77466:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 9 previous similar messages [ 3803.900768] Lustre: server umount lustre-MDT0000 complete [ 3809.312148] Lustre: Failing over lustre-MDT0001 [ 3809.857194] Lustre: server umount lustre-MDT0001 complete [ 3817.520319] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3828.127184] Lustre: 16419:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788840911/real 1788840911] req@ffff8a7fc5e09880 x1875732116120320/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788840927 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3828.161635] Lustre: 16419:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 26 previous similar messages [ 3830.190987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3839.726943] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3850.717910] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3862.671565] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3879.393134] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866da6d0f [ 3879.415138] Lustre: MGC192.168.204.153@tcp: Connection restored to 0@lo (at 0@lo) [ 3879.417809] Lustre: Skipped 10 previous similar messages [ 3880.002852] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3880.009327] Lustre: Skipped 2 previous similar messages [ 3885.341248] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3893.899332] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3894.395586] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 3894.395823] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 3896.436730] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3896.447455] Lustre: Skipped 2 previous similar messages [ 3896.484673] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3896.503375] Lustre: Skipped 2 previous similar messages [ 3896.551726] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 3896.554019] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 3900.095393] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3909.204272] Lustre: *** cfs_fail_loc=190, val=1*** [ 3909.204359] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32003: rc = 0 [ 3909.235152] Lustre: Skipped 39 previous similar messages [ 3912.534111] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 3919.855648] Lustre: Failing over lustre-MDT0000 [ 3920.141443] Lustre: server umount lustre-MDT0000 complete [ 3923.506328] Lustre: Failing over lustre-MDT0001 [ 3923.791305] Lustre: server umount lustre-MDT0001 complete [ 3932.734525] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3939.110766] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3948.157552] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3948.605360] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 3948.605860] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 3953.075416] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3953.762458] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:513) [ 3953.765117] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 3958.174801] Lustre: Failing over lustre-MDT0000 [ 3958.475063] Lustre: server umount lustre-MDT0000 complete [ 3962.468021] Lustre: Failing over lustre-MDT0001 [ 3963.040650] Lustre: server umount lustre-MDT0001 complete [ 3972.573255] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3972.692549] Lustre: *** cfs_fail_loc=190, val=1*** [ 3972.703221] Lustre: Skipped 24 previous similar messages [ 3978.198229] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3987.816570] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3988.319199] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 3988.330212] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 3993.745982] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:545) [ 3993.747103] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 3994.629295] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4011.479374] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 00:18:28 (1788841108) [ 4026.371580] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 4045.320942] Lustre: 128171:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4045.330348] Lustre: 128171:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4069.914967] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4101.534828] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 00:19:58 (1788841198) [ 4106.674732] Lustre: *** cfs_fail_loc=195, val=0*** [ 4111.307104] Lustre: Failing over lustre-OST0000 [ 4111.329686] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4111.333985] 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 [ 4111.336484] LustreError: Skipped 5 previous similar messages [ 4111.336824] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 4111.346566] Lustre: Skipped 21 previous similar messages [ 4111.361437] Lustre: Skipped 1 previous similar message [ 4111.503234] Lustre: server umount lustre-OST0000 complete [ 4121.992988] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4122.281905] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4122.293651] Lustre: Skipped 7 previous similar messages [ 4129.283603] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4319.269190] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 00:23:36 (1788841416) [ 4322.736895] Lustre: *** cfs_fail_loc=196, val=0*** [ 4322.743845] Lustre: Skipped 63 previous similar messages [ 4327.894342] Lustre: Failing over lustre-OST0000 [ 4328.093786] Lustre: server umount lustre-OST0000 complete [ 4336.258551] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4342.057198] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4531.907832] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 00:27:09 (1788841629) [ 4537.842483] Lustre: *** cfs_fail_loc=196, val=0*** [ 4537.850233] Lustre: Skipped 63 previous similar messages [ 4540.178236] Lustre: *** cfs_fail_loc=196, val=0*** [ 4540.182383] Lustre: Skipped 223 previous similar messages [ 4544.482618] Lustre: *** cfs_fail_loc=196, val=0*** [ 4544.484558] Lustre: Skipped 383 previous similar messages [ 4554.858554] Lustre: Failing over lustre-OST0000 [ 4554.942575] Lustre: server umount lustre-OST0000 complete [ 4556.785797] LustreError: 97677:0:(ldlm_lib.c:1190: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. [ 4556.808629] LustreError: 97677:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 38 previous similar messages [ 4564.214341] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4564.440979] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4564.449411] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4564.458101] Lustre: Skipped 4 previous similar messages [ 4565.667847] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4565.671565] Lustre: Skipped 4 previous similar messages [ 4565.698988] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4565.699068] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4565.703620] Lustre: Skipped 4 previous similar messages [ 4565.715910] Lustre: Skipped 19 previous similar messages [ 4569.391767] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4582.372172] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4584.929055] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4584.946430] Lustre: Skipped 3 previous similar messages [ 4586.664544] Lustre: server umount lustre-MDT0000 complete [ 4590.671063] LustreError: 88039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788841690 with bad export cookie 14670059931971517038 [ 4590.675964] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4590.679679] LustreError: 88039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 4590.691598] LustreError: Skipped 3 previous similar messages [ 4590.911174] Lustre: server umount lustre-MDT0001 complete [ 4604.455333] Lustre: server umount lustre-OST0000 complete [ 4618.202410] Lustre: server umount lustre-OST0001 complete [ 4628.319875] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 00:28:45 (1788841725) [ 4646.294132] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_hostid [ 4654.171297] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 4699.115443] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 4710.537805] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4710.774561] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4710.805475] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4710.897241] Lustre: lustre-MDT0000: new disk, initializing [ 4711.025977] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4715.807773] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4726.238473] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4726.344837] Lustre: 139474:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 4726.353353] Lustre: 139474:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4726.370550] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4726.374866] Lustre: Skipped 1 previous similar message [ 4726.433343] Lustre: lustre-MDT0001: new disk, initializing [ 4726.505645] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4726.511049] Lustre: Skipped 2 previous similar messages [ 4726.536605] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4726.549935] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4730.996829] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4735.777749] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4741.748558] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4741.908386] Lustre: lustre-OST0000: new disk, initializing [ 4741.911943] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4741.916985] Lustre: 141103:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4743.829884] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4743.852969] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4743.991120] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4748.381148] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4759.363081] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4759.476950] Lustre: lustre-OST0001: new disk, initializing [ 4759.480443] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4759.485498] Lustre: 141975:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4761.010602] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4761.022972] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4761.064721] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4765.814736] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4775.214917] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4779.264591] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4798.298716] Lustre: Failing over lustre-MDT0000 [ 4798.433040] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4798.440574] LustreError: Skipped 3 previous similar messages [ 4798.447523] 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 [ 4798.466631] Lustre: Skipped 8 previous similar messages [ 4798.478605] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4798.709942] Lustre: server umount lustre-MDT0000 complete [ 4802.420692] Lustre: Failing over lustre-MDT0001 [ 4802.705996] Lustre: server umount lustre-MDT0001 complete [ 4808.580901] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4818.282317] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4822.431104] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788841906/real 1788841906] req@ffff8a7fc63adf80 x1875732116720256/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788841922 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4822.468463] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 4825.823570] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4837.175600] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4850.801762] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4850.828922] Lustre: lustre-MDT0000: reset Object Index mappings [ 4850.833672] Lustre: Skipped 2 previous similar messages [ 4872.672437] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xcb9685c866dc8b2d [ 4878.207710] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4886.193447] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4886.547525] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 4886.551491] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 4890.665409] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4891.691062] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 4891.692164] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 4943.065597] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 00:34:00 (1788842040) [ 4957.503615] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 4999.453346] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5029.071738] Lustre: Failing over lustre-MDT0000 [ 5029.110090] Lustre: *** cfs_fail_loc=199, val=0*** [ 5029.123830] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5029.132074] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5029.146029] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5029.154505] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5029.162397] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5029.171143] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5029.183683] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5029.193817] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5029.203747] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5029.212847] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5029.223534] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5029.234611] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5029.252986] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5029.272909] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5029.288899] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5029.298709] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5029.318390] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5029.338589] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5029.360613] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5029.368114] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5029.376294] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5029.383797] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5029.390393] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5029.403946] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5029.412188] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5029.419855] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5029.427537] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5029.434982] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5029.440667] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5029.448473] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5029.454714] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5029.463146] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5029.474775] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5029.483666] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5029.493812] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5029.501784] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5029.511155] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5029.520752] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5029.530905] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5029.538760] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5029.552663] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5029.559672] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5029.568089] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5029.575762] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5029.593243] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5029.607263] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5029.619748] Lustre: *** cfs_fail_loc=199, val=0*** [ 5029.628017] Lustre: Skipped 45 previous similar messages [ 5029.631809] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5029.661744] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5029.671947] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5029.687160] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5029.697544] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5029.723585] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5029.739653] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5029.748717] Lustre: 151726:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5029.857499] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5029.988553] Lustre: server umount lustre-MDT0000 complete [ 5033.723415] Lustre: Failing over lustre-MDT0001 [ 5033.740362] Lustre: *** cfs_fail_loc=199, val=0*** [ 5033.748745] Lustre: Skipped 7 previous similar messages [ 5033.752685] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5033.765707] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5033.777991] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5033.785322] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5033.793122] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5033.808314] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5033.830419] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5033.851648] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5033.865492] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5033.873221] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5033.884941] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5033.893271] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5033.907673] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5033.915779] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5033.925943] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5033.933332] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5033.941255] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5033.953416] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5033.976617] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5033.993485] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5034.008517] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5034.016411] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5034.023927] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5034.033655] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5034.044767] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5034.062382] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5034.071962] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5034.080262] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5034.088872] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5034.097152] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5034.104761] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5034.110712] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5034.117775] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5034.125372] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5034.133869] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5034.139905] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5034.145668] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5034.150188] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5034.155978] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5034.160957] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5034.166332] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5034.175090] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5034.181234] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5034.191484] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5034.198555] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5034.211229] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5034.221651] Lustre: 151927:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5034.597584] Lustre: server umount lustre-MDT0001 complete [ 5042.394399] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5042.508726] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5042.517150] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5042.526405] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5042.535469] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5042.545919] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5042.558864] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5042.567232] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5042.578485] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5042.592046] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5042.608615] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5042.619352] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5042.637942] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5042.647469] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5042.661578] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5042.676887] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5042.689073] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5042.702321] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5042.713176] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5042.728227] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5042.744289] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5042.754717] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5042.772186] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5042.791032] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5042.810870] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5042.825325] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5042.835827] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5042.843852] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5042.855332] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5042.883285] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5042.897542] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5042.904402] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5042.920723] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5042.943427] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5042.976441] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5042.991832] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5043.012394] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5043.031837] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5043.043822] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5043.058726] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5043.067851] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5043.077933] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5043.085642] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5043.098399] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5043.111477] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5043.123658] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5043.140982] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5043.174765] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5043.186813] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5043.203385] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5043.220604] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5043.240842] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5043.262582] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5043.278977] Lustre: 152424:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5044.128025] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7eca946300 x1875732116888832/t0(0) o250->MGC192.168.204.153@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 [ 5048.692843] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5057.652583] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5057.814527] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5057.827352] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5057.837166] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5057.850535] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5057.859764] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5057.873921] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5057.884658] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5057.896588] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5057.908093] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5057.917701] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5057.930631] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5057.940838] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5057.951616] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5057.961647] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5057.970248] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5057.979856] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5057.988781] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5057.998625] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5058.010495] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5058.026695] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5058.035872] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5058.047404] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5058.065424] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5058.079029] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5058.105076] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5058.124360] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5058.136642] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5058.149033] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5058.168045] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5058.182454] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5058.201576] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5058.219774] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5058.232648] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5058.242504] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5058.251955] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5058.263966] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5058.280776] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5058.292523] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5058.302270] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5058.321958] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5058.340303] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5058.349187] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5058.356263] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5058.364230] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5058.371595] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5058.379349] Lustre: 153168:0:(osd_scrub.c:1854:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5058.691088] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 5058.691578] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 5063.744546] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 5063.746823] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5064.062666] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5074.676531] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 00:36:11 (1788842171) [ 5075.876544] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5075.886170] Lustre: Skipped 123 previous similar messages [ 5077.688074] Lustre: Failing over lustre-MDT0000 [ 5078.084814] Lustre: server umount lustre-MDT0000 complete [ 5092.997791] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5097.578628] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5098.546941] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5098.550153] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 5101.023479] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 00:36:38 (1788842198) [ 5102.066609] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5103.690889] Lustre: Failing over lustre-MDT0000 [ 5103.895045] Lustre: server umount lustre-MDT0000 complete [ 5118.188118] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5122.653456] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5124.131961] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 5124.132479] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5126.359708] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 00:37:03 (1788842223) [ 5148.384421] Lustre: Failing over lustre-MDT0000 [ 5148.747418] Lustre: server umount lustre-MDT0000 complete [ 5152.401144] Lustre: Failing over lustre-MDT0001 [ 5152.619966] Lustre: server umount lustre-MDT0001 complete [ 5160.269133] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5162.399139] LustreError: 157208:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 5162.406543] LustreError: 157208:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8a7eca7ff800 x1875732117045632/t0(0) o250->MGC192.168.204.153@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1788842262 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_01.0' uid:0 gid:0 projid:4294967295 [ 5162.427357] LustreError: 157208:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 5162.912888] LustreError: 16416:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7eca7fd180 x1875732117047040/t0(0) o250->MGC192.168.204.153@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 [ 5163.147776] LustreError: 151404:0:(ldlm_lib.c:1190: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. [ 5163.162948] LustreError: 151404:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 59 previous similar messages [ 5167.195513] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5169.646423] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5169.655735] Lustre: Skipped 20 previous similar messages [ 5175.420186] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5175.786528] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5175.790669] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 5180.344078] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5180.914190] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5180.922907] Lustre: Skipped 4 previous similar messages [ 5180.951207] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5180.962315] Lustre: Skipped 4 previous similar messages [ 5180.997188] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5180.998423] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 5186.101500] Lustre: Failing over lustre-MDT0000 [ 5186.349306] Lustre: server umount lustre-MDT0000 complete [ 5189.744710] Lustre: Failing over lustre-MDT0001 [ 5190.038634] Lustre: server umount lustre-MDT0001 complete [ 5198.737939] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5198.774748] Lustre: lustre-MDT0000: reset Object Index mappings [ 5198.779597] Lustre: Skipped 1 previous similar message [ 5199.720830] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5199.727893] Lustre: Skipped 5 previous similar messages [ 5203.822496] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5212.481454] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5212.809131] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5212.815876] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 5218.132828] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5218.361155] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:289) [ 5218.362762] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5229.656518] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 00:38:47 (1788842327) [ 5238.753032] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5245.229633] Lustre: server umount lustre-MDT0000 complete [ 5250.012271] LustreError: 151516:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788842349 with bad export cookie 14670059931971713892 [ 5250.012633] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5250.021111] LustreError: 151516:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 5250.048660] LustreError: Skipped 6 previous similar messages [ 5250.685239] Lustre: server umount lustre-MDT0001 complete [ 5266.041700] Lustre: server umount lustre-OST0000 complete [ 5271.200820] Lustre: server umount lustre-OST0001 complete [ 5278.640883] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5288.034247] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5303.647459] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5308.767324] LustreError: 161936:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.153@tcp: failed processing log, type 4: rc = -110 [ 5334.432143] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5334.441621] Lustre: Skipped 12 previous similar messages [ 5341.464924] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5347.256255] Lustre: Failing over lustre-OST0000 [ 5347.410701] Lustre: server umount lustre-OST0000 complete [ 5353.976752] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5362.652914] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5378.207418] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5383.327532] LustreError: 163461:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.153@tcp: failed processing log, type 4: rc = -110 [ 5415.322966] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5423.785993] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 00:42:00 (1788842520) [ 5439.384792] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 5450.090238] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5450.744527] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5455.068696] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5462.658737] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5462.985712] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5466.530632] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5469.844793] Lustre: 166366:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5469.854302] Lustre: 166366:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 2 previous similar messages [ 5485.767084] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5491.200434] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:257) [ 5491.210635] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 5492.294442] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5499.834700] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5505.581040] Lustre: *** cfs_fail_loc=193, val=0*** [ 5507.467895] Lustre: Failing over lustre-MDT0000 [ 5507.620414] Lustre: *** cfs_fail_loc=193, val=0*** [ 5507.705819] Lustre: server umount lustre-MDT0000 complete [ 5509.095306] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5509.104453] LustreError: Skipped 8 previous similar messages [ 5509.114133] 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 [ 5509.147366] Lustre: Skipped 34 previous similar messages [ 5518.179330] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5518.440539] Lustre: *** cfs_fail_loc=193, val=0*** [ 5523.078912] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5524.045297] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 5524.046791] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5526.902179] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5526.905092] Lustre: Skipped 4 previous similar messages [ 5526.913922] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5526.915483] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5526.916587] Lustre: Skipped 38 previous similar messages [ 5541.536367] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 00:43:58 (1788842638) [ 5544.038125] Lustre: Failing over lustre-MDT0000 [ 5544.302837] Lustre: server umount lustre-MDT0000 complete [ 5548.524397] Lustre: Failing over lustre-MDT0001 [ 5548.796788] Lustre: server umount lustre-MDT0001 complete [ 5551.465682] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5557.760432] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5562.862216] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5565.407187] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788842649/real 1788842649] req@ffff8a7ecb3e1f80 x1875732117230336/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788842665 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5565.435518] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 39 previous similar messages [ 5569.437828] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5573.415572] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5575.441235] LustreError: 170878:0:(update_trans.c:1081:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5575.460607] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5575.460607] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 5575.537904] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 5575.543375] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:289) [ 5578.512243] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5583.931256] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 00:44:41 (1788842681) [ 5590.498254] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5590.502466] Lustre: Skipped 10 previous similar messages [ 5592.655493] Lustre: server umount lustre-MDT0000 complete [ 5596.791433] Lustre: server umount lustre-MDT0001 complete [ 5611.641486] Lustre: server umount lustre-OST0000 complete [ 5625.665208] Lustre: server umount lustre-OST0001 complete [ 5632.937967] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5644.880391] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5650.352576] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5656.293715] Lustre: Failing over lustre-MDT0000 [ 5656.305995] LustreError: 173271:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5656.320283] LustreError: 173271:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5656.327732] LustreError: 173271:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 11, retries 0, failed: rc = -5 [ 5656.730302] Lustre: server umount lustre-MDT0000 complete [ 5663.471756] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5676.618698] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5681.858264] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5690.340424] Lustre: DEBUG MARKER: === sanity-scrub: start setup 00:46:27 (1788842787) === [ 5692.646705] LustreError: 174908:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5692.662912] LustreError: 174908:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5692.686260] LustreError: 174908:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 15, retries 0, failed: rc = -5 [ 5692.975255] Lustre: server umount lustre-MDT0000 complete [ 5727.031839] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_hostid [ 5734.459387] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 5783.001423] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing load_modules_local [ 5800.511644] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5800.739176] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5800.781564] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5800.907898] Lustre: lustre-MDT0000: new disk, initializing [ 5801.117367] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5807.130954] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5823.831682] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5823.936521] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5823.941579] Lustre: Skipped 1 previous similar message [ 5824.044271] Lustre: lustre-MDT0001: new disk, initializing [ 5824.130855] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5824.143314] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5828.779515] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5833.974347] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5843.681295] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5843.960783] Lustre: lustre-OST0000: new disk, initializing [ 5843.964917] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5843.972335] Lustre: 182209:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5845.389698] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5845.396105] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5845.482119] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5849.920544] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5862.427623] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5862.605120] Lustre: lustre-OST0001: new disk, initializing [ 5862.610400] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5862.617486] Lustre: 183234:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5864.646167] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5864.657746] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5864.736700] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5868.759268] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5878.556050] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5882.118975] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5888.604457] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 00:49:45 (1788842985) === [ 5890.430656] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 5594 sec ========= 00:49:47 (1788842987) [ 5892.447309] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 00:49:49 (1788842989) === [ 5895.918745] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 00:49:53 (1788842993) === [ 5900.772465] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5900.781815] Lustre: Skipped 3 previous similar messages [ 5907.021027] Lustre: server umount lustre-MDT0000 complete [ 5911.007887] LustreError: 181295:0:(ldlm_lib.c:1190: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. [ 5911.036971] LustreError: 181295:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 77 previous similar messages [ 5915.062668] LustreError: 180260:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788843014 with bad export cookie 14670059931971740387 [ 5915.064413] LustreError: MGC192.168.204.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5915.071561] LustreError: 180260:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 5915.076984] LustreError: Skipped 3 previous similar messages [ 5915.403832] Lustre: server umount lustre-MDT0001 complete [ 5933.590421] Lustre: server umount lustre-OST0000 complete [ 5942.591476] Lustre: server umount lustre-OST0001 complete [ 5961.033180] Lustre: DEBUG MARKER: oleg453-server.virtnet: executing unload_modules_local [ 5963.607240] Key type lgssc unregistered [ 5963.943465] LNet: 186643:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5963.957991] LNetError: 186643:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5963.990956] LNet: Removed LNI 192.168.204.153@tcp [ 5964.670515] Key type .llcrypt unregistered [ 5964.672374] Key type ._llcrypt unregistered