[ 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-8.fc42 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 487231827 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 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524588K 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.001014] APIC: Switch to symmetric I/O mode setup [ 0.003360] x2apic enabled [ 0.004008] Switched APIC routing to physical x2apic. [ 0.005013] kvm-guest: setup PV IPIs [ 0.008306] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009023] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010013] pid_max: default: 32768 minimum: 301 [ 0.011157] LSM: Security Framework initializing [ 0.012065] Yama: becoming mindful. [ 0.013034] SELinux: Initializing. [ 0.014071] *** VALIDATE selinux *** [ 0.022807] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027041] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028149] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029105] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030116] *** VALIDATE tmpfs *** [ 0.032377] *** VALIDATE proc *** [ 0.033263] *** VALIDATE cgroup *** [ 0.034009] *** VALIDATE cgroup2 *** [ 0.035254] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037110] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039031] Spectre V2 : User space: Vulnerable [ 0.040009] Speculative Store Bypass: Vulnerable [ 0.044260] debug: unmapping init [mem 0xffffffffbe059000-0xffffffffbe060fff] [ 0.046299] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047804] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048023] ... version: 2 [ 0.049012] ... bit width: 48 [ 0.050011] ... generic registers: 4 [ 0.051014] ... value mask: 0000ffffffffffff [ 0.052013] ... max period: 00007fffffffffff [ 0.053015] ... fixed-purpose events: 3 [ 0.054010] ... event mask: 000000070000000f [ 0.055321] rcu: Hierarchical SRCU implementation. [ 0.057690] smp: Bringing up secondary CPUs ... [ 0.058587] x86: Booting SMP configuration: [ 0.059024] .... node #0, CPUs: #1 #2 #3 [ 0.063066] smp: Brought up 1 node, 4 CPUs [ 0.065018] smpboot: Max logical packages: 1 [ 0.066010] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.103018] node 0 deferred pages initialised in 35ms [ 0.108122] devtmpfs: initialized [ 0.109346] x86/mm: Memory block size: 128MB [ 0.112391] gcov: version magic: 0x41383552 [ 0.114744] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.121168] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.127384] pinctrl core: initialized pinctrl subsystem [ 0.130604] [ 0.132007] ************************************************************* [ 0.135024] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.138023] ** ** [ 0.146240] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.150023] ** ** [ 0.153047] ** This means that this kernel is built to expose internal ** [ 0.158037] ** IOMMU data structures, which may compromise security on ** [ 0.164028] ** your system. ** [ 0.169047] ** ** [ 0.174204] ** If you see this message and you are not debugging the ** [ 0.179084] ** kernel, report this immediately to your vendor! ** [ 0.184034] ** ** [ 0.190030] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.195014] ************************************************************* [ 0.199227] NET: Registered protocol family 16 [ 0.202727] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.206076] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.210112] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.217101] cpuidle: using governor menu [ 0.218583] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.223810] PCI: Using configuration type 1 for base access [ 0.227187] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.246325] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.247043] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.249194] cryptd: max_cpu_qlen set to 1000 [ 0.258843] ACPI: Added _OSI(Module Device) [ 0.262025] ACPI: Added _OSI(Processor Device) [ 0.264016] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.266016] ACPI: Added _OSI(Processor Aggregator Device) [ 0.272161] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.278462] ACPI: Interpreter enabled [ 0.281067] ACPI: PM: (supports S0 S3 S4 S5) [ 0.283012] ACPI: Using IOAPIC for interrupt routing [ 0.286187] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.293168] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.312980] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.317104] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.337050] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.342085] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.349000] acpiphp: Slot [2] registered [ 0.351155] acpiphp: Slot [5] registered [ 0.352000] acpiphp: Slot [6] registered [ 0.352000] acpiphp: Slot [7] registered [ 0.355143] acpiphp: Slot [8] registered [ 0.357180] acpiphp: Slot [9] registered [ 0.359121] acpiphp: Slot [10] registered [ 0.361109] acpiphp: Slot [3] registered [ 0.362166] acpiphp: Slot [4] registered [ 0.365124] acpiphp: Slot [11] registered [ 0.367100] acpiphp: Slot [12] registered [ 0.368117] acpiphp: Slot [13] registered [ 0.370110] acpiphp: Slot [14] registered [ 0.371110] acpiphp: Slot [15] registered [ 0.374081] acpiphp: Slot [16] registered [ 0.375102] acpiphp: Slot [17] registered [ 0.376094] acpiphp: Slot [18] registered [ 0.378094] acpiphp: Slot [19] registered [ 0.379000] acpiphp: Slot [20] registered [ 0.380077] acpiphp: Slot [21] registered [ 0.382095] acpiphp: Slot [22] registered [ 0.383070] acpiphp: Slot [23] registered [ 0.386134] acpiphp: Slot [24] registered [ 0.387094] acpiphp: Slot [25] registered [ 0.389072] acpiphp: Slot [26] registered [ 0.390075] acpiphp: Slot [27] registered [ 0.392114] acpiphp: Slot [28] registered [ 0.395362] acpiphp: Slot [29] registered [ 0.398411] acpiphp: Slot [30] registered [ 0.400072] acpiphp: Slot [31] registered [ 0.402101] PCI host bridge to bus 0000:00 [ 0.403017] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.406024] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.408018] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.411023] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.413022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.417026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.419129] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.423718] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.428905] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.445746] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.452181] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.457040] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.460043] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.464045] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.468857] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.473147] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.478103] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.483729] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.488851] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.502017] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.510030] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.521232] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.534020] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.550021] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.579019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.594998] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.602018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.610015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.626017] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.649323] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.690041] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.705016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.738033] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.755548] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.774019] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.786046] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.808028] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.822000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.837015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.848024] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.864021] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.881000] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.887014] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.894017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.908023] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.921047] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.925522] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.928510] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.931495] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.934272] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.939070] iommu: Default domain type: Passthrough [ 0.942135] SCSI subsystem initialized [ 0.944652] ACPI: bus type USB registered [ 0.947318] usbcore: registered new interface driver usbfs [ 0.950113] usbcore: registered new interface driver hub [ 0.953126] usbcore: registered new device driver usb [ 0.956186] pps_core: LinuxPPS API ver. 1 registered [ 0.959013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.963064] PTP clock support registered [ 0.967057] EDAC MC: Ver: 3.0.0 [ 0.969132] PCI: Using ACPI for IRQ routing [ 0.973184] NetLabel: Initializing [ 1.017045] NetLabel: domain hash size = 128 [ 1.026022] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.038091] NetLabel: unlabeled traffic allowed by default [ 1.041318] vgaarb: loaded [ 1.044061] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.052044] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.067671] clocksource: Switched to clocksource kvm-clock [ 1.233943] VFS: Disk quotas dquot_6.6.0 [ 1.235678] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.237907] *** VALIDATE ramfs *** [ 1.238996] *** VALIDATE hugetlbfs *** [ 1.240358] pnp: PnP ACPI init [ 1.242490] pnp: PnP ACPI: found 6 devices [ 1.257825] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.260690] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.262556] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.264502] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.266661] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.268823] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.271339] NET: Registered protocol family 2 [ 1.273812] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.278965] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.284565] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.289707] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.293025] TCP: Hash tables configured (established 65536 bind 65536) [ 1.295801] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.298966] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.301761] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.304712] NET: Registered protocol family 1 [ 1.307250] RPC: Registered named UNIX socket transport module. [ 1.309432] RPC: Registered udp transport module. [ 1.311933] RPC: Registered tcp transport module. [ 1.313540] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.315945] NET: Registered protocol family 44 [ 1.317566] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.319654] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.321763] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.324422] PCI: CLS 0 bytes, default 64 [ 1.325802] Unpacking initramfs... [ 3.175896] debug: unmapping init [mem 0xffff8a7b7cc54000-0xffff8a7b7ffbffff] [ 3.182341] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 3.186137] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 3.190771] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.755563] Initialise system trusted keyrings [ 3.758262] Key type blacklist registered [ 3.761215] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.772315] zbud: loaded [ 3.775882] *** VALIDATE nfs *** [ 3.777540] *** VALIDATE nfs4 *** [ 3.779427] pstore: using deflate compression [ 3.783681] Platform Keyring initialized [ 3.909660] NET: Registered protocol family 38 [ 3.911680] Key type asymmetric registered [ 3.914639] Asymmetric key parser 'x509' registered [ 3.916395] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.919954] io scheduler mq-deadline registered [ 3.922287] io scheduler kyber registered [ 3.924324] io scheduler bfq registered [ 3.926631] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.930485] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.933838] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.936952] ACPI: Power Button [PWRF] [ 3.943642] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.950822] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.962864] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.971690] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.989244] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 4.018394] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 4.050340] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 4.055987] Non-volatile memory driver v1.3 [ 4.058874] Linux agpgart interface v0.103 [ 4.107841] virtio_blk virtio1: [vda] 134040 512-byte logical blocks (68.6 MB/65.4 MiB) [ 4.111381] vda: detected capacity change from 0 to 68628480 [ 4.132815] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.136501] vdb: detected capacity change from 0 to 1073741824 [ 4.160225] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.163755] vdc: detected capacity change from 0 to 2621440000 [ 4.182193] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.186106] vdd: detected capacity change from 0 to 2621440000 [ 4.207515] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.211383] vde: detected capacity change from 0 to 4294967296 [ 4.230401] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.233930] vdf: detected capacity change from 0 to 4294967296 [ 4.248431] libphy: Fixed MDIO Bus: probed [ 4.258207] usbcore: registered new interface driver usbserial_generic [ 4.260710] usbserial: USB Serial support registered for generic [ 4.263366] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.270761] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.273174] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.276402] mousedev: PS/2 mouse device common for all mice [ 4.280994] rtc_cmos 00:05: RTC can wake from S4 [ 4.284811] rtc_cmos 00:05: registered as rtc0 [ 4.290480] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.293796] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.296842] intel_pstate: CPU model not supported [ 4.304409] hid: raw HID events driver (C) Jiri Kosina [ 4.308826] usbcore: registered new interface driver usbhid [ 4.311993] usbhid: USB HID core driver [ 4.316925] drop_monitor: Initializing network drop monitor service [ 4.319772] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.322587] Initializing XFRM netlink socket [ 4.327690] NET: Registered protocol family 10 [ 4.331310] Segment Routing with IPv6 [ 4.332726] NET: Registered protocol family 17 [ 4.336643] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.343267] mpls_gso: MPLS GSO support [ 4.352366] RAS: Correctable Errors collector initialized. [ 4.356587] AVX version of gcm_enc/dec engaged. [ 4.359538] AES CTR mode by8 optimization enabled [ 4.481229] sched_clock: Marking stable (4481030546, 0)->(5460026491, -978995945) [ 4.617883] registered taskstats version 1 [ 4.621815] Loading compiled-in X.509 certificates [ 4.624731] zswap: loaded using pool lzo/zbud [ 4.657644] Key type big_key registered [ 4.673349] Key type encrypted registered [ 4.675278] ima: No TPM chip found, activating TPM-bypass! [ 4.677606] ima: Allocated hash algorithm: sha1 [ 4.679558] ima: No architecture policies found [ 4.681592] evm: Initialising EVM extended attributes: [ 4.683775] evm: security.selinux [ 4.685349] evm: security.ima [ 4.686575] evm: security.capability [ 4.687906] evm: HMAC attrs: 0x1 [ 4.690704] rtc_cmos 00:05: setting system clock to 2026-01-22 09:15:09 UTC (1769073309) [ 4.701335] debug: unmapping init [mem 0xffffffffbf003000-0xffffffffbf1fffff] [ 4.705406] debug: unmapping init [mem 0xffffffffbdd82000-0xffffffffbe058fff] [ 4.715523] Write protecting the kernel read-only data: 28672k [ 4.719719] debug: unmapping init [mem 0xffffffffbc403000-0xffffffffbc5fffff] [ 4.722895] debug: unmapping init [mem 0xffffffffbcd14000-0xffffffffbcdfffff] [ 4.772786] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 4.785842] systemd[1]: Detected virtualization kvm. [ 4.788926] systemd[1]: Detected architecture x86-64. [ 4.793328] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.833374] systemd[1]: No hostname configured. [ 4.835226] systemd[1]: Set hostname to . [ 4.837595] random: systemd: uninitialized urandom read (16 bytes read) [ 4.840286] systemd[1]: Initializing machine ID from random generator. [ 4.917902] random: ln: uninitialized urandom read (6 bytes read) [ 5.084562] random: systemd: uninitialized urandom read (16 bytes read) [ 5.087717] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 5.093730] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 5.102460] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Slices. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... Starting Apply Kernel Variables... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 6.429462] device-mapper: uevent: version 1.0.3 [ 6.432267] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 8.100019] random: fast init done [ 8.743803] virtio_net virtio0 ens2: renamed from eth0 [ 9.547930] scsi host0: ata_piix [ 9.618036] scsi host1: ata_piix [ 9.619461] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 9.628204] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 14.200598] random: crng init done [ 14.204254] random: 7 urandom warning(s) missed due to ratelimiting [ 16.807209] dracut-initqueue[581]: RTNETLINK answers: File exists 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... [ 19.327738] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 23.579451] printk: systemd: 26 output lines suppressed due to ratelimiting [ 24.828243] SELinux: Disabled at runtime. [ 25.075819] 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) [ 25.109376] systemd[1]: Detected virtualization kvm. [ 25.124655] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 28.148690] systemd[1]: initrd-switch-root.service: Succeeded. [ 28.175348] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 28.201645] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 28.219628] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 28.228147] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 28.256057] systemd[1]: Starting Journal Service... Starting Journal Service... [ 28.291704] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit to trigger not loaded. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on udev Control Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. Starting Remount Root and Kernel File Systems... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. Mounting Huge Pages File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 29.172042] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Reached target Local Encrypted Volumes. Starting Apply Kernel Variables... Mounting Kernel Debug File System... Starting udev Coldplug all Devices... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-getty.slice. Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 31.679282] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 34.045885] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 34.556944] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 35.414076] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 35.539035] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…only root support (10s / no limit) [** ] A start job is running for Configur…only root support (11s / no limit) [*** ] A start job is running for Configur…only root support (11s / no limit) [ *** ] A start job is running for Configur…only root support (12s / no limit) [ *** ] A start job is running for Configur…only root support (13s / no limit) [ ***] A start job is running for Configur…only root support (13s / no limit) [ **] A start job is running for Configur…only root support (14s / no limit) [ *] A start job is running for Configur…only root support (14s / no limit) [ **] A start job is running for Configur…only root support (15s / no limit) [ ***] A start job is running for Configur…only root support (16s / no limit)[ 44.291326] Key type dns_resolver registered [ *** ] A start job is running for Configur…only root support (16s / no limit) [ *** ] A start job is running for Configur…only root support (17s / no limit)[ 45.548727] NFS: Registering the id_resolver key type [ 45.550763] Key type id_resolver registered [ 45.552958] Key type id_legacy registered [*** ] A start job is running for Configur…only root support (18s / no limit) [** ] A start job is running for Configur…only root support (18s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Load/Save Random Seed. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. [ OK ] Started irqbalance daemon. Starting Login Service... Starting Network Manager... [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg120-server login: [ 101.723484] hrtimer: interrupt took 19473218 ns [ 125.881352] libcfs: loading out-of-tree module taints kernel. [ 125.964566] Key type ._llcrypt registered [ 125.967912] Key type .llcrypt registered [ 126.178277] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_hostid [ 151.264474] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 153.350306] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 153.376513] alg: No test for adler32 (adler32-zlib) [ 155.527354] Lustre: Lustre: Build Version: 2.17.50_3_g69d656b [ 157.074141] LNet: Added LNI 192.168.201.120@tcp [8/256/0/180] [ 158.912262] Key type lgssc registered [ 161.538910] Lustre: Echo OBD driver; http://www.lustre.org/ [ 187.849204] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 189.987799] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 201.196078] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 211.977505] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 224.409227] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 249.173872] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 267.524622] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 267.690927] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 267.752430] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 269.345779] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 269.415234] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 269.561275] Lustre: lustre-MDT0000: new disk, initializing [ 269.724066] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 269.759726] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 276.665541] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 297.104246] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 297.241673] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 297.332664] Lustre: 6522:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 297.391436] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 297.400893] Lustre: Skipped 1 previous similar message [ 297.507563] Lustre: lustre-MDT0001: new disk, initializing [ 297.595974] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 297.629640] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 297.648568] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 303.587197] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 309.575261] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 323.086098] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 323.158366] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 323.366938] Lustre: lustre-OST0000: new disk, initializing [ 323.375985] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 323.464413] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 331.325832] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 331.342564] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 331.463140] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 332.179895] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 351.538314] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 351.636828] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 351.810598] Lustre: lustre-OST0001: new disk, initializing [ 351.815073] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 351.926621] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 357.475189] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 357.498227] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 357.611174] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 360.114969] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 374.075509] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 381.972067] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 395.768219] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing check_logdir /tmp/testlogs/ [ 401.876466] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing yml_node [ 408.117479] Lustre: DEBUG MARKER: Client: 2.17.50.3 [ 411.869447] Lustre: DEBUG MARKER: MDS: 2.17.50.3 [ 414.948460] Lustre: DEBUG MARKER: OSS: 2.17.50.3 [ 416.971962] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Thu Jan 22 04:21:58 EST 2026 [ 438.561750] Lustre: DEBUG MARKER: excepting tests: [ 452.122241] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 465.381558] 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 [ 465.390138] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 465.395469] Lustre: Skipped 1 previous similar message [ 465.424414] Lustre: Skipped 3 previous similar messages [ 470.498649] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 470.521241] Lustre: Skipped 3 previous similar messages [ 471.216842] LustreError: 12596:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 471.519175] Lustre: server umount lustre-MDT0000 complete [ 480.740046] LustreError: 6531:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 480.784413] LustreError: 6531:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 482.845597] LustreError: 6514:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769073787 with bad export cookie 914390985558729646 [ 482.846833] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 482.865855] LustreError: 6514:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 483.033754] LustreError: 13049:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 483.039778] LustreError: 13049:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 483.734561] Lustre: server umount lustre-MDT0001 complete [ 502.176151] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769073790/real 1769073790] req@ffff8a7be7907480 x1855007973556864/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769073806 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 502.249976] 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 [ 502.282076] Lustre: Skipped 2 previous similar messages [ 503.266661] Lustre: 3656:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769073792/real 1769073792] req@ffff8a7ac500f100 x1855007973557120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769073808 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 504.466393] LustreError: 13500:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 504.472050] LustreError: 13500:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 504.926660] Lustre: server umount lustre-OST0000 complete [ 506.542072] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769073795/real 1769073795] req@ffff8a7ac500c700 x1855007973557376/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769073811 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 510.691709] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769073799/real 1769073799] req@ffff8a7ac500f800 x1855007973558016/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769073815 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 510.731855] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 514.856281] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769073803/real 1769073803] req@ffff8a7ac4c93480 x1855007973558272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769073819 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 516.119792] LustreError: 13952:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 516.128937] LustreError: 13952:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 516.387634] Lustre: server umount lustre-OST0001 complete [ 537.410230] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing unload_modules_local [ 541.532814] Key type lgssc unregistered [ 542.105723] LNet: 14734:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 542.143088] LNetError: 14734:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 543.208203] LNet: Removed LNI 192.168.201.120@tcp [ 544.772335] Key type .llcrypt unregistered [ 544.790034] Key type ._llcrypt unregistered [ 575.166824] Key type ._llcrypt registered [ 575.169137] Key type .llcrypt registered [ 575.324674] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_hostid [ 595.154221] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 596.975922] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 597.036868] alg: No test for adler32 (adler32-zlib) [ 598.213437] Lustre: Lustre: Build Version: 2.17.50_3_g69d656b [ 598.462732] LNet: Added LNI 192.168.201.120@tcp [8/256/0/180] [ 600.184179] Key type lgssc registered [ 601.708941] Lustre: Echo OBD driver; http://www.lustre.org/ [ 616.244483] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 625.702874] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 634.415124] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 644.998858] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 664.124954] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 681.763752] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 681.880959] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 681.901133] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 683.180297] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 683.207861] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 683.308170] Lustre: lustre-MDT0000: new disk, initializing [ 683.390062] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 683.408725] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 689.094275] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 706.412521] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 706.519476] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 706.618195] Lustre: 19154:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 706.685583] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 706.693202] Lustre: Skipped 1 previous similar message [ 706.873761] Lustre: lustre-MDT0001: new disk, initializing [ 707.007216] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 707.073702] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 707.103393] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 711.864902] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 717.156868] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 728.520786] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 728.619364] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 728.947809] Lustre: lustre-OST0000: new disk, initializing [ 728.958667] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 729.039090] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 737.028719] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 738.362981] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 738.376264] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 738.491534] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 753.691322] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 753.824721] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 753.934341] Lustre: lustre-OST0001: new disk, initializing [ 753.938935] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 754.050079] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 761.711347] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 762.423476] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 762.440905] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 762.560351] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 776.561316] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 785.603472] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 801.570579] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 04:28:23 (1769074103) === [ 804.086813] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 04:28:25 (1769074105) [ 830.227647] Lustre: Failing over lustre-MDT0000 [ 830.449936] LustreError: 23418:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 830.574819] Lustre: server umount lustre-MDT0000 complete [ 834.530125] 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 [ 834.542769] Lustre: Skipped 1 previous similar message [ 835.332285] LustreError: 20097:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074140 with bad export cookie 9516433293722430801 [ 835.334485] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 835.352402] LustreError: 20097:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 835.356239] Lustre: Failing over lustre-MDT0001 [ 835.634898] LustreError: 23618:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 835.642631] LustreError: 23618:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 836.206239] Lustre: server umount lustre-MDT0001 complete [ 846.810392] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 856.032182] Lustre: 16320:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074144/real 1769074144] req@ffff8a7bfd3b0380 x1855008437053312/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074160 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 856.038742] 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 [ 856.086866] Lustre: 16320:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 856.126228] Lustre: Skipped 3 previous similar messages [ 856.801447] Lustre: 16318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074145/real 1769074145] req@ffff8a7ac50ae300 x1855008437053696/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074161 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 860.257034] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074149/real 1769074149] req@ffff8a7ac50ac700 x1855008437054080/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074165 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 860.258071] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a91106edcb [ 860.296580] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 860.341265] Lustre: MGC192.168.201.120@tcp: Connection restored to 0@lo (at 0@lo) [ 860.743612] LustreError: 21060:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 860.764643] LustreError: 21060:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 860.905537] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 860.958993] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 861.945347] LustreError: 21060:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 866.018510] LustreError: 24082:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 866.035154] LustreError: 24082:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 866.923119] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074155/real 1769074155] req@ffff8a7aca88c380 x1855008437054720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074171 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 866.959741] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 867.162788] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 871.075703] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074159/real 1769074159] req@ffff8a7bfd3b2300 x1855008437054976/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074175 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 871.109026] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 871.409033] LustreError: 24082:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 871.458942] LustreError: 24082:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 874.483730] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 877.368880] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 877.802880] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 878.034259] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 878.104363] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 878.111185] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 883.184458] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 883.198721] Lustre: Skipped 1 previous similar message [ 883.205658] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 883.236788] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 883.304318] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 883.310897] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 883.332930] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 899.627379] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 04:30:01 (1769074201) [ 928.319872] Lustre: Failing over lustre-MDT0000 [ 928.593753] LustreError: 25782:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 928.607879] LustreError: 25782:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 929.029908] Lustre: server umount lustre-MDT0000 complete [ 929.250551] 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 [ 929.252461] LustreError: 24528:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 929.266796] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 929.280646] Lustre: Skipped 3 previous similar messages [ 929.325493] LustreError: 24528:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 934.025615] LustreError: 19146:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074238 with bad export cookie 9516433293722447307 [ 934.028705] Lustre: Failing over lustre-MDT0001 [ 934.030157] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 934.046990] LustreError: 19146:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 934.306576] LustreError: 25983:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 934.313495] LustreError: 25983:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 934.376741] 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 [ 934.610517] Lustre: server umount lustre-MDT0001 complete [ 946.348307] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 958.946166] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7be7906d80 x1855008437174784/t0(0) o250->MGC192.168.201.120@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 [ 959.371427] LustreError: 21060:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 959.394619] LustreError: 21060:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 959.490166] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 959.559746] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 960.483230] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 960.497227] Lustre: Skipped 2 previous similar messages [ 964.520534] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 975.092084] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 975.433629] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 975.719835] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 975.747480] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 980.972837] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 980.978416] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 980.989996] Lustre: Skipped 1 previous similar message [ 981.021663] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 981.030872] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 981.081886] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 981.082366] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 985.393522] Lustre: *** cfs_fail_loc=193, val=0*** [ 991.647199] Lustre: Failing over lustre-MDT0000 [ 991.851937] LustreError: 27762:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 991.870960] LustreError: 27762:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 992.259250] Lustre: server umount lustre-MDT0000 complete [ 996.328938] 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 [ 996.348227] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 996.358939] Lustre: Skipped 1 previous similar message [ 996.381054] LustreError: 27411:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 996.410026] LustreError: 27411:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 1002.976774] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1003.152565] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1003.394065] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1003.397836] Lustre: Skipped 1 previous similar message [ 1003.421425] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1008.616161] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1008.628090] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1008.658952] Lustre: Skipped 2 previous similar messages [ 1008.705079] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1008.785283] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 1008.785325] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 1008.851163] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1021.207216] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 04:32:02 (1769074322) [ 1037.825292] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 1058.246374] Lustre: 30262:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1083.759981] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1087.571530] Lustre: 31399:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1106.764277] Lustre: *** cfs_fail_loc=198, val=0*** [ 1118.795594] Lustre: Failing over lustre-MDT0000 [ 1118.995106] LustreError: 31721:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1119.005960] LustreError: 31721:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1119.089544] Lustre: server umount lustre-MDT0000 complete [ 1121.278450] 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 [ 1121.305671] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1121.339131] Lustre: Skipped 5 previous similar messages [ 1121.384490] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 1123.347670] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074428 with bad export cookie 9516433293722476392 [ 1123.350947] Lustre: Failing over lustre-MDT0001 [ 1123.355326] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1123.370328] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1123.873355] Lustre: server umount lustre-MDT0001 complete [ 1128.976440] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1134.677148] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1142.688144] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074431/real 1769074431] req@ffff8a7acbbf3100 x1855008437345152/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074447 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1142.737807] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1142.747117] 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 [ 1142.758324] Lustre: Skipped 1 previous similar message [ 1143.905721] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1148.909103] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a91107c91e [ 1148.934238] Lustre: MGC192.168.201.120@tcp: Connection restored to 0@lo (at 0@lo) [ 1148.939171] Lustre: Skipped 3 previous similar messages [ 1149.542077] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1149.596801] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1153.874972] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1163.623261] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1163.934797] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1164.064973] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1164.150980] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:171 to 0x280000400:193) [ 1164.155989] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 1168.979977] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1169.424359] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 1169.504324] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:203 to 0x280000401:225) [ 1169.504664] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 1185.870824] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 04:34:47 (1769074487) [ 1210.378133] Lustre: Failing over lustre-MDT0000 [ 1210.582425] LustreError: 34569:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1210.601480] LustreError: 34569:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1210.941781] Lustre: server umount lustre-MDT0000 complete [ 1215.457358] 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 [ 1215.476977] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1215.479220] LustreError: 32871:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1215.479232] LustreError: 32871:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 1215.671405] Lustre: Failing over lustre-MDT0001 [ 1215.674443] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074520 with bad export cookie 9516433293722503454 [ 1215.674904] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1215.711215] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1216.083877] Lustre: server umount lustre-MDT0001 complete [ 1221.320344] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1227.099885] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1236.960173] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074525/real 1769074525] req@ffff8a7acba27480 x1855008437470720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074541 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1237.008574] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1237.757770] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1237.825478] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 1241.124251] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bca9fa300 x1855008437472384/t0(0) o250->MGC192.168.201.120@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 [ 1241.840651] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1247.226489] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1255.413787] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1255.423564] Lustre: Skipped 5 previous similar messages [ 1258.182247] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1258.236874] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1258.433379] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1258.653675] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 1258.657693] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 1263.536332] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1263.586552] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1263.654487] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1263.717691] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 1263.718115] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1290.723421] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 1316.003718] Lustre: 38621:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1344.409861] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1348.500744] Lustre: 39759:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1377.171174] Lustre: Failing over lustre-MDT0000 [ 1377.336286] LustreError: 39987:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1377.343834] LustreError: 39987:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1377.535210] Lustre: server umount lustre-MDT0000 complete [ 1381.362085] 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 [ 1381.365169] LustreError: 35719:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1381.379128] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1381.393649] Lustre: Skipped 8 previous similar messages [ 1381.446299] LustreError: 35719:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 17 previous similar messages [ 1381.719409] Lustre: Failing over lustre-MDT0001 [ 1381.721431] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074686 with bad export cookie 9516433293722531384 [ 1381.727228] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1381.765383] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1382.403660] Lustre: server umount lustre-MDT0001 complete [ 1387.481543] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1395.078796] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1402.853419] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074691/real 1769074691] req@ffff8a7be7905f80 x1855008437627392/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074707 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1402.908100] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 1408.345512] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1408.450816] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1426.528756] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7be7904700 x1855008437629696/t0(0) o250->MGC192.168.201.120@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 [ 1427.204224] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1427.211788] Lustre: Skipped 3 previous similar messages [ 1427.250735] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1432.454961] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1442.076609] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1442.117810] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1442.415849] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1442.422665] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:298 to 0x280000400:321) [ 1446.498319] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1446.510462] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1446.528322] Lustre: Skipped 4 previous similar messages [ 1446.564202] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1446.643283] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 1446.643440] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1447.074401] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1473.533372] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 1492.067912] Lustre: 44428:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1515.426777] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1519.647559] Lustre: 45563:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1546.625109] Lustre: Failing over lustre-MDT0000 [ 1546.832152] LustreError: 45792:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1546.839378] LustreError: 45792:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1547.101730] Lustre: server umount lustre-MDT0000 complete [ 1549.285707] 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 [ 1549.292894] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1549.312698] Lustre: Skipped 4 previous similar messages [ 1549.330878] LustreError: Skipped 1 previous similar message [ 1550.947292] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769074855 with bad export cookie 9516433293722559153 [ 1550.948490] Lustre: Failing over lustre-MDT0001 [ 1550.949663] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1550.959293] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1551.446656] Lustre: server umount lustre-MDT0001 complete [ 1556.923504] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1562.866615] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1570.784128] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769074859/real 1769074859] req@ffff8a7bfe662a00 x1855008437779712/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769074875 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1570.813725] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 1575.156959] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1575.190892] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1576.725631] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1580.508429] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1589.068058] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1589.137995] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1589.251953] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1589.254246] Lustre: Skipped 4 previous similar messages [ 1589.603230] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1589.606996] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1593.295646] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1594.860949] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1594.935978] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1594.996462] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 1594.996462] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1608.798299] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 04:41:50 (1769074910) [ 1625.904114] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 1645.722638] Lustre: 50228:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1668.417479] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1697.067878] Lustre: Failing over lustre-MDT0000 [ 1697.256540] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1697.269953] Lustre: Skipped 3 previous similar messages [ 1697.354330] LustreError: 51591:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1697.381116] LustreError: 51591:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1697.565478] Lustre: server umount lustre-MDT0000 complete [ 1701.829800] LustreError: 20097:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769075006 with bad export cookie 9516433293722586922 [ 1701.837679] Lustre: Failing over lustre-MDT0001 [ 1701.838508] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1701.848382] LustreError: 20097:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1702.256805] Lustre: server umount lustre-MDT0001 complete [ 1707.528403] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1716.046616] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1716.912793] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1718.501026] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769075007/real 1769075007] req@ffff8a7bfd41ce00 x1855008437929472/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769075023 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1718.540290] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1726.748531] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1735.193793] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1736.153131] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1747.532819] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1747.553163] Lustre: lustre-MDT0000: reset Object Index mappings [ 1772.139869] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1772.153205] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 24 previous similar messages [ 1772.247917] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1772.252953] Lustre: Skipped 3 previous similar messages [ 1772.285524] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1777.262244] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1786.255350] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1786.269294] Lustre: lustre-MDT0001: reset Object Index mappings [ 1786.577769] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1786.592814] LustreError: Skipped 1 previous similar message [ 1786.766989] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:426 to 0x2c0000400:449) [ 1786.771768] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1787.753943] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1787.794964] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1787.852828] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1787.859692] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1791.257308] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1803.682143] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 04:45:05 (1769075105) [ 1827.393399] Lustre: Failing over lustre-MDT0000 [ 1827.756537] Lustre: server umount lustre-MDT0000 complete [ 1828.840400] 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 [ 1828.861174] Lustre: Skipped 9 previous similar messages [ 1831.562411] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769075136 with bad export cookie 9516433293722614691 [ 1831.568896] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1831.578175] LustreError: 19145:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1831.590124] Lustre: Failing over lustre-MDT0001 [ 1831.913475] Lustre: server umount lustre-MDT0001 complete [ 1838.158232] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1847.684921] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1848.612902] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1857.197352] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1867.118963] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1868.199691] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1882.603560] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1882.618478] Lustre: lustre-MDT0000: reset Object Index mappings [ 1902.221780] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1907.841616] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1917.424102] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1917.429598] Lustre: Skipped 9 previous similar messages [ 1919.461225] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1919.476105] Lustre: lustre-MDT0001: reset Object Index mappings [ 1919.885402] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1919.890052] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1924.455336] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1925.097097] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1925.134570] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1925.198978] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1925.211624] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1933.203846] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64024: rc = 0 [ 1934.430397] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/64033 with flags 0x52: rc = 0 [ 1956.861928] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 04:47:39 (1769075259) [ 1978.064801] Lustre: Failing over lustre-MDT0000 [ 1978.249786] LustreError: 59991:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1978.260817] LustreError: 59991:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 1978.419748] Lustre: server umount lustre-MDT0000 complete [ 1982.192048] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769075287 with bad export cookie 9516433293722642348 [ 1982.196836] Lustre: Failing over lustre-MDT0001 [ 1982.197352] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1982.200664] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1982.646871] Lustre: server umount lustre-MDT0001 complete [ 1988.276422] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1998.841208] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2000.246582] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2002.916098] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769075291/real 1769075291] req@ffff8a7bfe663b80 x1855008438171264/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769075307 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2002.972121] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 26 previous similar messages [ 2010.610404] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2020.339591] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2021.401253] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2034.519338] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2034.538124] Lustre: lustre-MDT0000: reset Object Index mappings [ 2052.258276] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bfe663480 x1855008438174976/t0(0) o250->MGC192.168.201.120@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 [ 2052.756463] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2058.641680] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2071.660087] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2071.692951] Lustre: lustre-MDT0001: reset Object Index mappings [ 2072.158132] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2072.169971] LustreError: Skipped 3 previous similar messages [ 2072.349887] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 2072.364700] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 2073.323355] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2073.372557] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2073.425343] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 2073.432637] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 2077.550263] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2088.046686] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32009: rc = 0 [ 2090.314486] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/96019 with flags 0x52: rc = 0 [ 2213.222551] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 04:51:55 (1769075515) [ 2251.366648] Lustre: Failing over lustre-MDT0000 [ 2251.705836] Lustre: server umount lustre-MDT0000 complete [ 2255.136143] Lustre: Failing over lustre-MDT0001 [ 2255.138822] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769075559 with bad export cookie 9516433293722669858 [ 2255.142801] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2255.146751] LustreError: 19147:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2255.549350] Lustre: server umount lustre-MDT0001 complete [ 2261.818768] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2272.018944] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2273.233569] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2282.284045] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2292.022452] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2293.187188] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2307.665531] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2307.697299] Lustre: lustre-MDT0000: reset Object Index mappings [ 2324.450396] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bf7160e00 x1855008438366720/t0(0) o250->MGC192.168.201.120@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 [ 2324.875840] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2324.891737] LustreError: 25050:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 24 previous similar messages [ 2324.995419] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2324.997903] Lustre: Skipped 5 previous similar messages [ 2325.049025] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2329.702542] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2339.799889] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2339.821232] Lustre: lustre-MDT0001: reset Object Index mappings [ 2340.366229] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 2340.371048] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 2342.372462] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2342.455626] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2342.522086] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2342.523874] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 2345.510105] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2354.788243] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32042: rc = 0 [ 2358.179666] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 2450.463699] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 04:55:51 (1769075751) [ 2465.391586] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2465.396388] Lustre: Skipped 1 previous similar message [ 2465.889851] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2465.893020] Lustre: Skipped 45 previous similar messages [ 2466.892626] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2466.894437] Lustre: Skipped 215 previous similar messages [ 2483.712561] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 04:56:25 (1769075785) [ 2488.540741] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2488.543703] Lustre: Skipped 193 previous similar messages [ 2488.916867] LustreError: 25571:0:(osd_compat.c:738:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 263/1394385998 264/3036723118 [ 2500.900404] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 04:56:42 (1769075802) [ 2516.452158] 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 [ 2516.464219] Lustre: Skipped 16 previous similar messages [ 2516.472016] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2517.474747] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2517.487522] Lustre: Skipped 1 previous similar message [ 2522.596083] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2522.605468] Lustre: Skipped 3 previous similar messages [ 2527.733381] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2527.737814] Lustre: Skipped 2 previous similar messages [ 2530.272238] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2530.397428] LustreError: 71769:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2530.407508] LustreError: 71769:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 2530.642225] Lustre: server umount lustre-MDT0000 complete [ 2535.162070] LustreError: 25573:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769075839 with bad export cookie 9516433293722714350 [ 2535.183719] LustreError: 25573:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2537.955059] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2537.960935] Lustre: Skipped 1 previous similar message [ 2541.891452] Lustre: server umount lustre-MDT0001 complete [ 2552.575392] Lustre: server umount lustre-OST0000 complete [ 2571.232994] Lustre: lustre-OST0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2571.598657] Lustre: server umount lustre-OST0001 complete [ 2579.734554] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_hostid [ 2590.976017] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 2602.539384] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2609.829563] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2617.807894] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2624.766049] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2638.614312] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 2649.201968] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2649.310190] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2649.595867] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2649.650431] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2649.779128] Lustre: lustre-MDT0000: new disk, initializing [ 2649.959275] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2654.245357] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2667.608038] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2667.688965] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2667.777489] Lustre: 75262:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2667.792459] Lustre: 75262:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 2667.834267] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2667.840481] Lustre: Skipped 1 previous similar message [ 2667.966980] Lustre: lustre-MDT0001: new disk, initializing [ 2668.099155] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2668.114086] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2673.150045] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2678.254760] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2685.674776] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2685.747265] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2685.944715] Lustre: lustre-OST0000: new disk, initializing [ 2685.953717] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2688.043094] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2688.062651] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2688.162936] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2693.822822] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2706.930519] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2707.037081] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2707.207529] Lustre: lustre-OST0001: new disk, initializing [ 2707.219540] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2708.400954] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2708.415800] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2708.518065] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2715.863207] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2726.847994] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2730.462662] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2754.010978] Lustre: Failing over lustre-MDT0000 [ 2754.315859] Lustre: server umount lustre-MDT0000 complete [ 2758.752249] Lustre: Failing over lustre-MDT0001 [ 2759.185428] Lustre: server umount lustre-MDT0001 complete [ 2765.463361] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2775.287530] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2776.036435] Lustre: 16320:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769076064/real 1769076064] req@ffff8a7bff5eb480 x1855008438688128/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769076080 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2776.086683] Lustre: 16320:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 2776.797158] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2785.305144] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2795.063084] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2795.999439] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2808.792699] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2808.821356] Lustre: lustre-MDT0000: reset Object Index mappings [ 2828.387617] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bc99e6680 x1855008438692096/t0(0) o250->MGC192.168.201.120@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 [ 2832.755381] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2841.474397] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2841.856360] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2841.867300] LustreError: Skipped 3 previous similar messages [ 2842.004263] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2842.017146] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2846.069397] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2846.083959] Lustre: Skipped 14 previous similar messages [ 2846.218409] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2846.221949] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2846.923551] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2857.674423] Lustre: *** cfs_fail_loc=190, val=3*** [ 2857.675092] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32004: rc = 0 [ 2858.743821] Lustre: *** cfs_fail_loc=190, val=3*** [ 2858.746691] Lustre: Skipped 1 previous similar message [ 2859.785129] Lustre: *** cfs_fail_loc=190, val=3*** [ 2860.955921] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 2862.816421] Lustre: *** cfs_fail_loc=190, val=3*** [ 2862.819134] Lustre: Skipped 2 previous similar messages [ 2867.041906] Lustre: *** cfs_fail_loc=191, val=3*** [ 2867.044679] Lustre: Skipped 2 previous similar messages [ 2871.579961] Lustre: Failing over lustre-MDT0000 [ 2871.854826] Lustre: server umount lustre-MDT0000 complete [ 2875.771927] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2875.774882] Lustre: Failing over lustre-MDT0001 [ 2875.780792] LustreError: Skipped 2 previous similar messages [ 2876.165445] Lustre: server umount lustre-MDT0001 complete [ 2887.861212] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2900.456249] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a9110cc299 [ 2900.965397] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2900.974205] Lustre: Skipped 1 previous similar message [ 2905.901565] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2917.653548] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2918.014867] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2918.043520] Lustre: Skipped 1 previous similar message [ 2918.166738] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 2918.169919] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2923.579654] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 2923.589568] Lustre: Skipped 1 previous similar message [ 2923.655398] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2923.658603] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2923.673378] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2929.427330] Lustre: Failing over lustre-MDT0000 [ 2929.789534] Lustre: server umount lustre-MDT0000 complete [ 2933.731141] LustreError: 76859:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2933.767403] LustreError: 76859:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 37 previous similar messages [ 2934.113801] Lustre: Failing over lustre-MDT0001 [ 2934.605631] Lustre: server umount lustre-MDT0001 complete [ 2948.117942] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2948.509448] Lustre: *** cfs_fail_loc=190, val=3*** [ 2958.385651] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a9110cc8ea [ 2958.936153] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2958.946328] Lustre: Skipped 9 previous similar messages [ 2964.225190] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2966.561250] Lustre: *** cfs_fail_loc=190, val=3*** [ 2966.564561] Lustre: Skipped 5 previous similar messages [ 2975.860438] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2976.148657] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 2976.160121] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2979.808598] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2981.479992] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2981.481700] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2989.299903] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x46:0x0]/88: rc = 0 [ 2989.300463] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 2999.857356] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 05:05:01 (1769076301) [ 3024.145231] Lustre: Failing over lustre-MDT0000 [ 3024.814212] Lustre: server umount lustre-MDT0000 complete [ 3029.197431] Lustre: Failing over lustre-MDT0001 [ 3029.675887] Lustre: server umount lustre-MDT0001 complete [ 3036.265277] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3046.342229] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3047.387356] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3057.659924] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3068.240720] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3069.379302] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3084.221854] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3084.255410] Lustre: lustre-MDT0000: reset Object Index mappings [ 3084.258487] Lustre: Skipped 1 previous similar message [ 3100.129258] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7accc43480 x1855008438876288/t0(0) o250->MGC192.168.201.120@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 [ 3106.259854] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3118.706414] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3119.204120] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 3119.210916] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 3124.269623] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 3124.279752] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 3124.605209] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3135.774447] Lustre: *** cfs_fail_loc=190, val=2*** [ 3135.776352] Lustre: Skipped 10 previous similar messages [ 3135.778156] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32011: rc = 0 [ 3139.195964] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 3152.240074] Lustre: lustre-MDT0001: trigger partial OI scrub for RPC inconsistency, checking FID [0x240001b71:0x45:0x0]/145: rc = 0 [ 3152.256962] Lustre: Skipped 1 previous similar message [ 3167.779977] Lustre: Failing over lustre-MDT0000 [ 3167.946822] LustreError: 91752:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 3167.952835] LustreError: 91752:0:(obd_class.h:479:obd_check_dev()) Skipped 89 previous similar messages [ 3168.144901] Lustre: server umount lustre-MDT0000 complete [ 3170.277263] 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 [ 3170.295574] Lustre: Skipped 31 previous similar messages [ 3172.552141] Lustre: Failing over lustre-MDT0001 [ 3172.557467] LustreError: 75252:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769076477 with bad export cookie 9516433293722872886 [ 3172.583991] LustreError: 75252:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 3173.084061] Lustre: server umount lustre-MDT0001 complete [ 3184.030882] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3197.921695] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bd7d50700 x1855008438923520/t0(0) o250->MGC192.168.201.120@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 [ 3202.272132] Lustre: *** cfs_fail_loc=190, val=3*** [ 3202.285932] Lustre: Skipped 31 previous similar messages [ 3204.356366] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3216.550771] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3217.464579] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 3217.486870] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 3222.629969] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 3222.629981] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 3222.797423] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3247.336812] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 05:09:09 (1769076549) [ 3266.516778] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 3288.163206] Lustre: 95663:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3313.602400] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3318.249981] Lustre: 96799:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3369.983789] Lustre: Failing over lustre-MDT0000 [ 3370.658682] Lustre: server umount lustre-MDT0000 complete [ 3375.107463] Lustre: Failing over lustre-MDT0001 [ 3375.761300] Lustre: server umount lustre-MDT0001 complete [ 3382.872982] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3391.396201] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769076680/real 1769076680] req@ffff8a7bfd41e680 x1855008439089792/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769076696 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3391.464933] Lustre: 16317:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 57 previous similar messages [ 3392.945163] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3394.224581] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3404.446885] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3416.726043] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3417.983833] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3438.613765] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3438.653061] Lustre: lustre-MDT0000: reset Object Index mappings [ 3438.663824] Lustre: Skipped 1 previous similar message [ 3445.794702] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a9110e42c7 [ 3454.753337] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3460.584735] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3460.602538] Lustre: Skipped 27 previous similar messages [ 3464.282384] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3464.585796] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 3464.599527] LustreError: Skipped 9 previous similar messages [ 3464.764580] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3464.768282] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 3469.026382] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3469.906698] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3469.908803] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 3479.552178] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/64002: rc = 0 [ 3479.555557] Lustre: *** cfs_fail_loc=190, val=3*** [ 3479.564695] Lustre: Skipped 14 previous similar messages [ 3482.872148] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32034 with flags 0x52: rc = 0 [ 3504.733616] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 05:13:26 (1769076806) [ 3553.419985] Lustre: Failing over lustre-MDT0000 [ 3553.778594] Lustre: server umount lustre-MDT0000 complete [ 3556.835534] LustreError: 76858:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3556.877061] LustreError: 76858:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 54 previous similar messages [ 3558.303598] Lustre: Failing over lustre-MDT0001 [ 3558.311981] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3558.319369] LustreError: Skipped 4 previous similar messages [ 3558.703860] Lustre: server umount lustre-MDT0001 complete [ 3566.097459] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3576.883081] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3578.265136] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3587.299468] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3596.572617] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3597.598980] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3610.551694] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3629.194135] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3629.202136] Lustre: Skipped 7 previous similar messages [ 3629.243929] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3629.258808] Lustre: Skipped 4 previous similar messages [ 3635.230284] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3645.757944] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3646.369513] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 3646.369623] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3647.336587] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3647.347942] Lustre: Skipped 4 previous similar messages [ 3647.381885] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3647.386821] Lustre: Skipped 4 previous similar messages [ 3647.456162] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 3647.457830] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3650.180440] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3692.481563] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 05:16:34 (1769076994) [ 3712.667596] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 3740.433660] Lustre: 108223:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3768.344971] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3772.836761] Lustre: 109358:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3884.182838] Lustre: Failing over lustre-MDT0000 [ 3884.686706] LustreError: 109927:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 3884.690725] LustreError: 109927:0:(obd_class.h:479:obd_check_dev()) Skipped 47 previous similar messages [ 3884.878238] Lustre: server umount lustre-MDT0000 complete [ 3888.103184] 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 [ 3888.115571] Lustre: Skipped 15 previous similar messages [ 3889.461644] LustreError: 75253:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769077194 with bad export cookie 9516433293723015441 [ 3889.465796] Lustre: Failing over lustre-MDT0001 [ 3889.482847] LustreError: 75253:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 14 previous similar messages [ 3890.600947] Lustre: server umount lustre-MDT0001 complete [ 3897.455580] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3910.351806] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3911.403806] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3926.159802] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3940.078826] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3941.224416] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3962.626481] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3962.667613] Lustre: lustre-MDT0000: reset Object Index mappings [ 3962.676432] Lustre: Skipped 3 previous similar messages [ 3985.185731] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a91112cedb [ 3992.757958] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4004.153176] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4004.547631] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 4004.568678] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 4005.656770] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 4005.664291] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 4009.845348] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4076.100146] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 05:22:58 (1769077378) [ 4091.151617] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 4110.503804] Lustre: 116139:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4138.231142] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4142.493208] Lustre: 117277:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4298.530562] Lustre: Failing over lustre-MDT0000 [ 4298.726120] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4298.746237] Lustre: Skipped 4 previous similar messages [ 4299.045537] Lustre: server umount lustre-MDT0000 complete [ 4303.765635] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4303.799872] LustreError: Skipped 1 previous similar message [ 4303.818787] Lustre: Failing over lustre-MDT0001 [ 4303.841457] LustreError: 112304:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4303.872460] LustreError: 112304:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 15 previous similar messages [ 4304.372625] Lustre: server umount lustre-MDT0001 complete [ 4311.630431] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4322.010237] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4323.152672] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4334.225082] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4345.367608] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4346.389770] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4362.107825] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4374.257514] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4374.271913] Lustre: Skipped 3 previous similar messages [ 4374.336224] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4374.348622] Lustre: Skipped 1 previous similar message [ 4378.360753] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4378.370790] Lustre: Skipped 15 previous similar messages [ 4381.438990] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4396.502230] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4397.031802] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 4397.052781] LustreError: Skipped 3 previous similar messages [ 4397.323847] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 4397.335671] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 4402.684893] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4402.709202] Lustre: Skipped 1 previous similar message [ 4402.767155] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4402.786365] Lustre: Skipped 1 previous similar message [ 4402.892025] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 4402.894416] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 4404.681965] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4414.944553] Lustre: *** cfs_fail_loc=190, val=1*** [ 4414.944564] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32002: rc = 0 [ 4414.946399] Lustre: Skipped 46 previous similar messages [ 4418.449568] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/96020 with flags 0x52: rc = 0 [ 4425.472105] Lustre: Failing over lustre-MDT0000 [ 4425.946572] Lustre: server umount lustre-MDT0000 complete [ 4430.263456] Lustre: Failing over lustre-MDT0001 [ 4430.893311] Lustre: server umount lustre-MDT0001 complete [ 4441.031340] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4449.761023] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769077738/real 1769077738] req@ffff8a7bd0406300 x1855008439755648/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769077754 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4449.802928] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 4462.112846] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4472.959864] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4473.339055] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 4473.343308] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 4478.533090] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 4478.535890] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 4479.122098] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4485.288908] Lustre: Failing over lustre-MDT0000 [ 4485.419057] LustreError: 123343:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 4485.425295] LustreError: 123343:0:(obd_class.h:479:obd_check_dev()) Skipped 47 previous similar messages [ 4485.599878] Lustre: server umount lustre-MDT0000 complete [ 4488.672560] 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 [ 4488.687732] Lustre: Skipped 19 previous similar messages [ 4490.110460] LustreError: 75252:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769077794 with bad export cookie 9516433293723927681 [ 4490.112883] Lustre: Failing over lustre-MDT0001 [ 4490.131714] LustreError: 75252:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 4490.832564] Lustre: server umount lustre-MDT0001 complete [ 4504.413624] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4504.604147] Lustre: *** cfs_fail_loc=190, val=1*** [ 4504.607543] Lustre: Skipped 26 previous similar messages [ 4514.272701] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bc499c380 x1855008439786112/t0(0) o250->MGC192.168.201.120@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 [ 4521.333505] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4532.145091] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4532.437258] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 4532.437464] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 4537.087507] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4537.959469] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 4537.959510] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:545) [ 4553.537099] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 05:30:55 (1769077855) [ 4569.496120] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 4592.001703] Lustre: 127056:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4618.695333] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4659.842927] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 05:32:42 (1769077962) [ 4665.478897] Lustre: *** cfs_fail_loc=195, val=0*** [ 4666.099410] Lustre: *** cfs_fail_loc=195, val=0*** [ 4666.103432] Lustre: Skipped 31 previous similar messages [ 4671.317818] Lustre: Failing over lustre-OST0000 [ 4671.417614] Lustre: server umount lustre-OST0000 complete [ 4682.434767] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4692.196955] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4886.534815] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 05:36:28 (1769078188) [ 4892.024945] Lustre: *** cfs_fail_loc=196, val=0*** [ 4892.030669] Lustre: Skipped 31 previous similar messages [ 4899.454579] Lustre: Failing over lustre-OST0000 [ 4899.724995] Lustre: server umount lustre-OST0000 complete [ 4908.026475] LustreError: 76847:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4908.072931] LustreError: 76847:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 46 previous similar messages [ 4909.826975] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4909.973767] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4917.259455] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5106.947568] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 05:40:09 (1769078409) [ 5113.266628] Lustre: *** cfs_fail_loc=196, val=0*** [ 5113.268318] Lustre: Skipped 63 previous similar messages [ 5117.284698] Lustre: *** cfs_fail_loc=196, val=0*** [ 5117.291462] Lustre: Skipped 415 previous similar messages [ 5131.558238] Lustre: Failing over lustre-OST0000 [ 5131.622652] LustreError: 132778:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 5131.632697] LustreError: 132778:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 5131.748882] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 5131.759349] LustreError: Skipped 7 previous similar messages [ 5131.765548] 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 [ 5131.783164] Lustre: Skipped 7 previous similar messages [ 5131.924978] Lustre: server umount lustre-OST0000 complete [ 5144.005638] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5144.485293] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 5144.500967] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5144.531949] Lustre: Skipped 4 previous similar messages [ 5146.380722] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5146.391721] Lustre: Skipped 4 previous similar messages [ 5146.441483] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 5146.466165] Lustre: Skipped 4 previous similar messages [ 5146.469939] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 5146.481238] Lustre: Skipped 18 previous similar messages [ 5152.083055] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5167.009673] Lustre: server umount lustre-MDT0000 complete [ 5172.971586] LustreError: 75253:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769078477 with bad export cookie 9516433293723929298 [ 5172.972203] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5172.982297] LustreError: 75253:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5172.986745] LustreError: Skipped 2 previous similar messages [ 5173.160791] Lustre: server umount lustre-MDT0001 complete [ 5187.439118] Lustre: server umount lustre-OST0000 complete [ 5201.947983] Lustre: server umount lustre-OST0001 complete [ 5213.654881] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 05:41:55 (1769078515) [ 5231.989544] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_hostid [ 5238.710563] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 5250.744087] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5261.220941] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5267.959259] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5274.561248] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5288.354923] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 5298.124862] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5298.186499] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5298.373883] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5298.422993] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5298.578752] Lustre: lustre-MDT0000: new disk, initializing [ 5298.680470] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5298.687142] Lustre: Skipped 6 previous similar messages [ 5298.709900] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5303.922143] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5313.827722] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5313.924933] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5314.018421] Lustre: 138329:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 5314.035706] Lustre: 138329:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 5314.061578] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5314.065421] Lustre: Skipped 1 previous similar message [ 5314.126548] Lustre: lustre-MDT0001: new disk, initializing [ 5314.211345] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5314.223667] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5319.093929] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5323.641902] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5329.867890] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5329.970898] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5330.165471] Lustre: lustre-OST0000: new disk, initializing [ 5330.170120] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5331.641846] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5331.659485] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5331.843901] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5337.052094] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5347.656921] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5347.767754] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5347.835638] Lustre: lustre-OST0001: new disk, initializing [ 5347.838926] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5349.088159] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5349.102248] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5349.223502] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5354.168880] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5363.430613] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5368.132902] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5389.297061] Lustre: Failing over lustre-MDT0000 [ 5391.594856] Lustre: server umount lustre-MDT0000 complete [ 5395.734157] Lustre: Failing over lustre-MDT0001 [ 5396.274277] Lustre: server umount lustre-MDT0001 complete [ 5401.609498] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5410.089740] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5411.233919] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5416.928816] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769078705/real 1769078705] req@ffff8a7bff007100 x1855008440341632/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769078721 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5416.964095] Lustre: 16319:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 5420.807886] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5430.788526] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5431.867247] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5444.328861] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5444.382693] Lustre: lustre-MDT0000: reset Object Index mappings [ 5444.400921] Lustre: Skipped 3 previous similar messages [ 5466.144881] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bff079f80 x1855008440344576/t0(0) o250->MGC192.168.201.120@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 [ 5472.557228] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5485.634626] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5486.253848] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 5486.267648] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 5487.308305] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 5487.320880] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 5490.599239] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5546.809419] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 05:47:28 (1769078848) [ 5566.644085] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 5587.761780] Lustre: 149007:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5613.336307] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5617.510382] Lustre: 150145:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5649.691239] Lustre: Failing over lustre-MDT0000 [ 5649.713185] Lustre: *** cfs_fail_loc=199, val=0*** [ 5649.726345] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5649.738813] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5649.758070] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5649.776207] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5649.784480] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5649.802871] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5649.821561] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5649.843514] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5649.853358] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5649.878155] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5649.892806] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5649.920790] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5649.932477] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5649.947339] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5649.959600] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5649.969394] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5649.986883] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5650.020284] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5650.031876] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5650.049987] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5650.071416] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5650.088673] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5650.107328] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5650.124558] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5650.146710] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5650.157963] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5650.170946] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5650.187984] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5650.201900] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5650.210187] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5650.234831] Lustre: *** cfs_fail_loc=199, val=0*** [ 5650.238183] Lustre: Skipped 29 previous similar messages [ 5650.241313] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5650.257707] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5650.272887] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5650.292502] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5650.307529] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5650.345720] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5650.358795] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5650.377720] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5650.402114] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5650.415983] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5650.423430] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5650.432128] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5650.437931] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5650.446704] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5650.455545] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5650.468897] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5650.482778] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5650.492988] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5650.500286] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5650.509190] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5650.520081] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5650.526922] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5650.545678] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5650.563272] Lustre: 150480:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5650.938787] Lustre: server umount lustre-MDT0000 complete [ 5651.436905] LustreError: 144145:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5651.471124] LustreError: 144145:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 30 previous similar messages [ 5655.685698] Lustre: Failing over lustre-MDT0001 [ 5655.713972] Lustre: *** cfs_fail_loc=199, val=0*** [ 5655.727280] Lustre: Skipped 23 previous similar messages [ 5655.729573] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5655.759570] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5655.774661] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5655.790824] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5655.805499] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5655.821975] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5655.831708] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5655.852622] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5655.871799] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5655.893866] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5655.911602] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5655.932696] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5655.950539] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5655.963847] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5655.980428] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5655.996774] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5656.016145] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5656.029788] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5656.048885] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5656.061452] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5656.086913] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5656.107568] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5656.125772] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5656.150085] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5656.173641] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5656.190792] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5656.210530] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5656.220724] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5656.248899] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5656.261356] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5656.281491] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5656.308178] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5656.327853] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5656.356632] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5656.377622] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5656.416586] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5656.469665] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5656.499638] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5656.524564] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5656.546503] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5656.565913] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5656.571257] Lustre: Skipped 2 previous similar messages [ 5656.582337] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5656.591675] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5656.605544] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5656.625459] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5656.646348] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5656.663875] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5656.676675] Lustre: 150682:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5657.682063] Lustre: server umount lustre-MDT0001 complete [ 5670.031158] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5670.126541] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5670.142850] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5670.154452] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5670.162885] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5670.179497] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5670.189411] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5670.199301] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5670.207494] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5670.216716] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5670.224848] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5670.234583] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5670.240460] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5670.247436] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5670.254161] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5670.263795] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5670.270770] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5670.278711] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5670.297504] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5670.309568] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5670.314699] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5670.321790] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5670.329465] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5670.337777] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5670.345401] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5670.353348] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5670.361178] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5670.368736] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5670.376664] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5670.384893] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5670.392767] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5670.399961] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5670.407491] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5670.412335] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5670.419846] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5670.425548] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5670.433884] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5670.439800] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5670.447062] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5670.452557] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5670.457845] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5670.467780] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5670.474654] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5670.484469] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5670.489146] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5670.494113] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5670.499045] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5670.513793] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5670.526883] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5670.533495] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5670.540076] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5670.547040] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5670.552784] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5670.559803] Lustre: 151179:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5681.062083] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x841129a911200f0a [ 5686.409924] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5697.694238] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5697.824242] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5697.845191] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5697.860681] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5697.871162] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5697.881962] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5697.901518] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5697.927277] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5697.943076] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5697.966636] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5697.992942] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5698.019250] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5698.037517] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5698.051671] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5698.079355] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5698.092100] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5698.114326] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5698.131367] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5698.147331] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5698.179392] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5698.204595] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5698.234192] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5698.259907] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5698.275897] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5698.285265] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5698.300840] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5698.317538] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5698.332413] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5698.354355] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5698.374358] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5698.396303] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5698.413874] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5698.423467] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5698.438676] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5698.462695] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5698.477680] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5698.502276] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5698.525227] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5698.542397] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5698.570988] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5698.583972] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5698.598743] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5698.640666] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5698.657629] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5698.677359] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5698.711607] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5698.732378] Lustre: 151911:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5699.306713] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 5699.306889] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 5704.085702] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5704.296302] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5704.308509] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 5717.578932] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 05:50:19 (1769079019) [ 5718.578177] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5718.584410] Lustre: Skipped 123 previous similar messages [ 5721.259452] Lustre: Failing over lustre-MDT0000 [ 5723.612338] Lustre: server umount lustre-MDT0000 complete [ 5745.379330] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5752.289524] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bc30e8e00 x1855008440557056/t0(0) o250->MGC192.168.201.120@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 [ 5752.455349] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5752.464510] Lustre: Skipped 2 previous similar messages [ 5753.764983] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5753.774521] Lustre: Skipped 2 previous similar messages [ 5757.514499] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5757.931156] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5757.941275] Lustre: Skipped 12 previous similar messages [ 5757.964598] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5757.967530] Lustre: Skipped 2 previous similar messages [ 5758.057861] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5758.071167] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 5761.421759] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 05:51:03 (1769079063) [ 5762.667904] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5764.792223] Lustre: Failing over lustre-MDT0000 [ 5764.972089] LustreError: 153921:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 5764.976353] LustreError: 153921:0:(obd_class.h:479:obd_check_dev()) Skipped 69 previous similar messages [ 5765.181391] Lustre: server umount lustre-MDT0000 complete [ 5768.167771] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5768.173174] 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 [ 5768.175629] LustreError: Skipped 4 previous similar messages [ 5768.197481] Lustre: Skipped 23 previous similar messages [ 5783.577367] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5783.780110] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5783.799972] LustreError: Skipped 3 previous similar messages [ 5789.481435] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5789.827829] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 5789.831078] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5794.237572] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 05:51:36 (1769079096) [ 5822.276202] Lustre: Failing over lustre-MDT0000 [ 5822.667832] Lustre: server umount lustre-MDT0000 complete [ 5826.748860] LustreError: 138321:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769079131 with bad export cookie 9516433293724096969 [ 5826.756432] LustreError: 138321:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 5826.759318] Lustre: Failing over lustre-MDT0001 [ 5827.105946] Lustre: server umount lustre-MDT0001 complete [ 5840.877713] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5859.142515] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5868.994950] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5869.385074] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5869.389192] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 5874.793426] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 5874.797607] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5875.304871] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5881.470932] Lustre: Failing over lustre-MDT0000 [ 5881.778211] Lustre: server umount lustre-MDT0000 complete [ 5885.423251] Lustre: Failing over lustre-MDT0001 [ 5886.112684] Lustre: server umount lustre-MDT0001 complete [ 5896.534662] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5896.556492] Lustre: lustre-MDT0000: reset Object Index mappings [ 5896.559996] Lustre: Skipped 1 previous similar message [ 5910.497414] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bff018e00 x1855008440712576/t0(0) o250->MGC192.168.201.120@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 [ 5911.078517] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5911.088268] Lustre: Skipped 11 previous similar messages [ 5915.862321] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5926.802569] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5927.308574] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 5927.345808] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5932.528731] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5932.657674] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5932.658057] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 5943.343446] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 05:54:05 (1769079245) [ 5952.994420] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5953.002791] Lustre: Skipped 3 previous similar messages [ 5958.139858] Lustre: server umount lustre-MDT0000 complete [ 5962.997366] Lustre: server umount lustre-MDT0001 complete [ 5978.263262] Lustre: server umount lustre-OST0000 complete [ 5982.521458] Lustre: server umount lustre-OST0001 complete [ 5990.469262] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 6001.393035] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6017.121218] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 6022.240315] LustreError: 160575:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.120@tcp: failed processing log, type 4: rc = -110 [ 6055.451152] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6061.387845] Lustre: Failing over lustre-OST0000 [ 6061.555659] Lustre: server umount lustre-OST0000 complete [ 6068.046501] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 6078.939874] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6094.496387] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 6099.616432] LustreError: 162086:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.120@tcp: failed processing log, type 4: rc = -110 [ 6131.456259] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6139.958365] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 05:57:22 (1769079442) [ 6152.940216] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 6162.121382] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6162.878963] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 6167.627427] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6175.203339] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6175.603308] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 6179.878388] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6183.015658] Lustre: 164930:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 6198.230053] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6200.212733] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 6200.243067] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 6204.374832] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6211.202863] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6221.474582] Lustre: *** cfs_fail_loc=193, val=0*** [ 6223.303932] Lustre: Failing over lustre-MDT0000 [ 6223.499523] Lustre: *** cfs_fail_loc=193, val=0*** [ 6223.679996] Lustre: server umount lustre-MDT0000 complete [ 6231.134181] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6231.329970] Lustre: *** cfs_fail_loc=193, val=0*** [ 6235.170334] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6236.703487] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 6236.708585] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 6239.104203] Lustre: *** cfs_fail_loc=19f, val=0*** [ 6239.104733] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 6239.108509] Lustre: Skipped 48 previous similar messages [ 6240.176267] Lustre: *** cfs_fail_loc=19f, val=0*** [ 6240.180841] Lustre: Skipped 5 previous similar messages [ 6253.590171] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 05:59:15 (1769079555) [ 6256.425324] Lustre: Failing over lustre-MDT0000 [ 6256.706673] Lustre: server umount lustre-MDT0000 complete [ 6257.123885] LustreError: 163810:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6257.133326] LustreError: 163810:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 124 previous similar messages [ 6260.275415] Lustre: Failing over lustre-MDT0001 [ 6260.462148] Lustre: server umount lustre-MDT0001 complete [ 6263.038303] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6269.055109] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6270.433024] LustreError: 16316:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8a7bc7758700 x1855008440865024/t0(0) o250->MGC192.168.201.120@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 [ 6274.251514] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6278.816084] Lustre: 16318:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079567/real 1769079567] req@ffff8a7ad2725500 x1855008440864128/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079583 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6278.844776] Lustre: 16318:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 32 previous similar messages [ 6282.084985] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6286.725715] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6288.203246] LustreError: 169386:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 6288.240678] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 6288.247628] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 6288.279450] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 6288.282402] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 6291.080512] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 6296.608369] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 05:59:59 (1769079599) [ 6303.203812] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6303.207758] Lustre: Skipped 1 previous similar message [ 6307.754968] Lustre: server umount lustre-MDT0000 complete [ 6311.617148] Lustre: server umount lustre-MDT0001 complete [ 6325.656892] Lustre: server umount lustre-OST0000 complete [ 6338.469424] Lustre: server umount lustre-OST0001 complete [ 6346.989650] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6360.226588] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6365.313079] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6371.145175] Lustre: Failing over lustre-MDT0000 [ 6371.150112] LustreError: 171758:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6371.157789] LustreError: 171758:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6371.163867] LustreError: 171758:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 10, retries 0, failed: rc = -5 [ 6371.265993] LustreError: 172285:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 6371.275378] LustreError: 172285:0:(obd_class.h:479:obd_check_dev()) Skipped 121 previous similar messages [ 6371.406785] Lustre: server umount lustre-MDT0000 complete [ 6377.812142] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6390.640674] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6395.807887] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6403.748582] Lustre: DEBUG MARKER: === sanity-scrub: start setup 06:01:46 (1769079706) === [ 6405.825091] LustreError: 173379:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 6405.839095] LustreError: 173379:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 6405.848267] LustreError: 173379:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 15, retries 0, failed: rc = -5 [ 6406.089914] Lustre: server umount lustre-MDT0000 complete [ 6438.583188] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_hostid [ 6445.510930] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 6455.512481] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6463.775302] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6470.597079] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6477.948883] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6491.372641] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing load_modules_local [ 6503.816224] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6503.891224] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6504.142784] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6504.174171] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6504.245188] Lustre: lustre-MDT0000: new disk, initializing [ 6504.325597] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6508.069818] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6520.957327] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6521.039362] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6521.099851] Lustre: 178684:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 6521.112218] Lustre: 178684:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 6521.172092] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6521.179996] Lustre: Skipped 1 previous similar message [ 6521.330712] Lustre: lustre-MDT0001: new disk, initializing [ 6521.507725] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6521.511026] Lustre: Skipped 12 previous similar messages [ 6521.602938] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6521.619733] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6526.499449] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6531.976803] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6541.639191] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6541.761956] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6542.031196] Lustre: lustre-OST0000: new disk, initializing [ 6542.038046] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6543.467076] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6543.475417] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6543.582449] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6548.104587] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6561.163972] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6561.280137] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6561.424780] Lustre: lustre-OST0001: new disk, initializing [ 6561.431168] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6563.231689] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6563.244882] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6563.283137] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6566.885389] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6575.935924] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6579.527264] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6590.262969] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 06:04:52 (1769079892) === [ 6591.460642] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 6173 sec ========= 06:04:54 (1769079894) [ 6592.843505] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 06:04:55 (1769079895) === [ 6595.543546] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 06:04:57 (1769079897) === [ 6599.139163] 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 [ 6599.140138] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6599.167383] Lustre: Skipped 33 previous similar messages [ 6599.167437] Lustre: Skipped 2 previous similar messages [ 6604.261684] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6604.274584] Lustre: Skipped 6 previous similar messages [ 6607.057764] Lustre: server umount lustre-MDT0000 complete [ 6614.916544] LustreError: 180596:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769079919 with bad export cookie 9516433293724152269 [ 6614.923537] LustreError: MGC192.168.201.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6614.926442] LustreError: 180596:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 6614.948354] LustreError: Skipped 6 previous similar messages [ 6615.261609] Lustre: server umount lustre-MDT0001 complete [ 6632.702219] Lustre: server umount lustre-OST0000 complete [ 6640.727503] Lustre: server umount lustre-OST0001 complete [ 6655.875817] Lustre: DEBUG MARKER: oleg120-server.virtnet: executing unload_modules_local [ 6658.509880] Key type lgssc unregistered [ 6658.752202] LNet: 184982:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6658.762029] LNetError: 184982:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6658.785498] LNet: Removed LNI 192.168.201.120@tcp [ 6659.617972] Key type .llcrypt unregistered [ 6659.620968] Key type ._llcrypt unregistered