[ 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 694979416 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, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.003153] x2apic enabled [ 0.004007] Switched APIC routing to physical x2apic. [ 0.005013] kvm-guest: setup PV IPIs [ 0.008298] ..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.009033] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010011] pid_max: default: 32768 minimum: 301 [ 0.011134] LSM: Security Framework initializing [ 0.012051] Yama: becoming mindful. [ 0.013036] SELinux: Initializing. [ 0.014080] *** VALIDATE selinux *** [ 0.022704] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027154] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029002] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030107] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031126] *** VALIDATE tmpfs *** [ 0.033037] *** VALIDATE proc *** [ 0.034206] *** VALIDATE cgroup *** [ 0.035010] *** VALIDATE cgroup2 *** [ 0.037233] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038156] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040023] Spectre V2 : User space: Vulnerable [ 0.041004] Speculative Store Bypass: Vulnerable [ 0.044003] debug: unmapping init [mem 0xffffffff96459000-0xffffffff96460fff] [ 0.046215] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047732] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048024] ... version: 2 [ 0.049011] ... bit width: 48 [ 0.050009] ... generic registers: 4 [ 0.051012] ... value mask: 0000ffffffffffff [ 0.052011] ... max period: 00007fffffffffff [ 0.053015] ... fixed-purpose events: 3 [ 0.054011] ... event mask: 000000070000000f [ 0.055304] rcu: Hierarchical SRCU implementation. [ 0.057424] smp: Bringing up secondary CPUs ... [ 0.058588] x86: Booting SMP configuration: [ 0.059023] .... node #0, CPUs: #1 #2 #3 [ 0.062797] smp: Brought up 1 node, 4 CPUs [ 0.064013] smpboot: Max logical packages: 1 [ 0.065018] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.147020] node 0 deferred pages initialised in 80ms [ 0.149225] devtmpfs: initialized [ 0.150228] x86/mm: Memory block size: 128MB [ 0.153117] gcov: version magic: 0x41383552 [ 0.155244] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.156081] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.159323] pinctrl core: initialized pinctrl subsystem [ 0.161191] [ 0.161768] ************************************************************* [ 0.164012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.166014] ** ** [ 0.169014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.171011] ** ** [ 0.174015] ** This means that this kernel is built to expose internal ** [ 0.176011] ** IOMMU data structures, which may compromise security on ** [ 0.179013] ** your system. ** [ 0.181010] ** ** [ 0.183012] ** If you see this message and you are not debugging the ** [ 0.186021] ** kernel, report this immediately to your vendor! ** [ 0.189014] ** ** [ 0.191010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.194012] ************************************************************* [ 0.197553] NET: Registered protocol family 16 [ 0.200832] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.202073] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.206067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.210098] cpuidle: using governor menu [ 0.212176] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.215462] PCI: Using configuration type 1 for base access [ 0.218138] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.227195] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.230025] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.234117] cryptd: max_cpu_qlen set to 1000 [ 0.238046] ACPI: Added _OSI(Module Device) [ 0.239011] ACPI: Added _OSI(Processor Device) [ 0.240011] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.242012] ACPI: Added _OSI(Processor Aggregator Device) [ 0.247000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.252475] ACPI: Interpreter enabled [ 0.253060] ACPI: PM: (supports S0 S3 S4 S5) [ 0.254011] ACPI: Using IOAPIC for interrupt routing [ 0.255089] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.257515] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.269525] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.272050] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.274015] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.275134] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.280476] acpiphp: Slot [2] registered [ 0.282071] acpiphp: Slot [5] registered [ 0.282858] acpiphp: Slot [6] registered [ 0.283087] acpiphp: Slot [7] registered [ 0.285117] acpiphp: Slot [8] registered [ 0.286098] acpiphp: Slot [9] registered [ 0.288107] acpiphp: Slot [10] registered [ 0.289061] acpiphp: Slot [3] registered [ 0.289921] acpiphp: Slot [4] registered [ 0.290074] acpiphp: Slot [11] registered [ 0.290952] acpiphp: Slot [12] registered [ 0.293071] acpiphp: Slot [13] registered [ 0.293973] acpiphp: Slot [14] registered [ 0.294073] acpiphp: Slot [15] registered [ 0.294881] acpiphp: Slot [16] registered [ 0.296090] acpiphp: Slot [17] registered [ 0.298244] acpiphp: Slot [18] registered [ 0.299077] acpiphp: Slot [19] registered [ 0.300054] acpiphp: Slot [20] registered [ 0.301074] acpiphp: Slot [21] registered [ 0.302082] acpiphp: Slot [22] registered [ 0.304088] acpiphp: Slot [23] registered [ 0.305084] acpiphp: Slot [24] registered [ 0.306094] acpiphp: Slot [25] registered [ 0.307198] acpiphp: Slot [26] registered [ 0.309073] acpiphp: Slot [27] registered [ 0.310090] acpiphp: Slot [28] registered [ 0.311090] acpiphp: Slot [29] registered [ 0.312111] acpiphp: Slot [30] registered [ 0.314079] acpiphp: Slot [31] registered [ 0.316067] PCI host bridge to bus 0000:00 [ 0.317019] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.320023] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.323022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.325022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.328023] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.331026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.332166] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.335349] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.339650] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.349018] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.353039] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.354011] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.355012] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.357011] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.359451] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.360522] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.363042] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.365578] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.368810] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.380017] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.385021] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.390668] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.399021] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.408016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.432019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.454404] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.467020] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.473015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.489026] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.497573] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.504016] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.510016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.534079] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.543065] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.549020] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.558021] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.571022] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.581761] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.587013] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.593016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.608019] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.616878] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.623094] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.628024] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.641022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.650749] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.651241] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.653294] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.655325] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.656213] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.661102] iommu: Default domain type: Passthrough [ 0.663388] SCSI subsystem initialized [ 0.664089] ACPI: bus type USB registered [ 0.665031] usbcore: registered new interface driver usbfs [ 0.666041] usbcore: registered new interface driver hub [ 0.668090] usbcore: registered new device driver usb [ 0.670181] pps_core: LinuxPPS API ver. 1 registered [ 0.672010] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.675047] PTP clock support registered [ 0.676124] EDAC MC: Ver: 3.0.0 [ 0.678508] PCI: Using ACPI for IRQ routing [ 0.680984] NetLabel: Initializing [ 0.682014] NetLabel: domain hash size = 128 [ 0.684009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.685077] NetLabel: unlabeled traffic allowed by default [ 0.687148] vgaarb: loaded [ 0.688248] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.689006] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.695000] clocksource: Switched to clocksource kvm-clock [ 0.791702] VFS: Disk quotas dquot_6.6.0 [ 0.793387] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.795418] *** VALIDATE ramfs *** [ 0.796795] *** VALIDATE hugetlbfs *** [ 0.798499] pnp: PnP ACPI init [ 0.801089] pnp: PnP ACPI: found 6 devices [ 0.819168] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.821551] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.822980] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.824207] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.825577] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.827024] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.829622] NET: Registered protocol family 2 [ 0.832310] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.837499] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.840896] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.846297] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.848855] TCP: Hash tables configured (established 65536 bind 65536) [ 0.852020] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.855300] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.857269] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.859030] NET: Registered protocol family 1 [ 0.860707] RPC: Registered named UNIX socket transport module. [ 0.862707] RPC: Registered udp transport module. [ 0.864431] RPC: Registered tcp transport module. [ 0.865619] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.868233] NET: Registered protocol family 44 [ 0.869596] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.871319] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.873194] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.875508] PCI: CLS 0 bytes, default 64 [ 0.877273] Unpacking initramfs... [ 2.347554] debug: unmapping init [mem 0xffff9155bcc54000-0xffff9155bffbffff] [ 2.354127] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.356770] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.361391] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.889184] Initialise system trusted keyrings [ 2.891174] Key type blacklist registered [ 2.893247] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.903159] zbud: loaded [ 2.906331] *** VALIDATE nfs *** [ 2.907725] *** VALIDATE nfs4 *** [ 2.909428] pstore: using deflate compression [ 2.913452] Platform Keyring initialized [ 3.049420] NET: Registered protocol family 38 [ 3.051836] Key type asymmetric registered [ 3.054030] Asymmetric key parser 'x509' registered [ 3.057024] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.060571] io scheduler mq-deadline registered [ 3.062760] io scheduler kyber registered [ 3.064829] io scheduler bfq registered [ 3.067221] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.070552] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.074316] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.077700] ACPI: Power Button [PWRF] [ 3.085387] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.093762] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.111094] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.120812] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.140450] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.170307] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.201231] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.207482] Non-volatile memory driver v1.3 [ 3.208620] Linux agpgart interface v0.103 [ 3.249973] virtio_blk virtio1: [vda] 134720 512-byte logical blocks (69.0 MB/65.8 MiB) [ 3.254343] vda: detected capacity change from 0 to 68976640 [ 3.275666] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.280509] vdb: detected capacity change from 0 to 1073741824 [ 3.296627] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.300337] vdc: detected capacity change from 0 to 2621440000 [ 3.317138] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.319489] vdd: detected capacity change from 0 to 2621440000 [ 3.335991] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.338151] vde: detected capacity change from 0 to 4294967296 [ 3.352691] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.355953] vdf: detected capacity change from 0 to 4294967296 [ 3.362309] libphy: Fixed MDIO Bus: probed [ 3.369892] usbcore: registered new interface driver usbserial_generic [ 3.372443] usbserial: USB Serial support registered for generic [ 3.374737] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.377800] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.379127] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.381040] mousedev: PS/2 mouse device common for all mice [ 3.383808] rtc_cmos 00:05: RTC can wake from S4 [ 3.386134] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.387295] rtc_cmos 00:05: registered as rtc0 [ 3.390796] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.391210] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.394358] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.396233] intel_pstate: CPU model not supported [ 3.397860] hid: raw HID events driver (C) Jiri Kosina [ 3.405019] usbcore: registered new interface driver usbhid [ 3.407199] usbhid: USB HID core driver [ 3.409050] drop_monitor: Initializing network drop monitor service [ 3.411135] Initializing XFRM netlink socket [ 3.413230] NET: Registered protocol family 10 [ 3.416722] Segment Routing with IPv6 [ 3.418739] NET: Registered protocol family 17 [ 3.421309] mpls_gso: MPLS GSO support [ 3.433214] RAS: Correctable Errors collector initialized. [ 3.434765] AVX version of gcm_enc/dec engaged. [ 3.436323] AES CTR mode by8 optimization enabled [ 3.521260] sched_clock: Marking stable (3521196890, 0)->(4378672071, -857475181) [ 3.523970] registered taskstats version 1 [ 3.525269] Loading compiled-in X.509 certificates [ 3.526878] zswap: loaded using pool lzo/zbud [ 3.544507] Key type big_key registered [ 3.557885] Key type encrypted registered [ 3.559353] ima: No TPM chip found, activating TPM-bypass! [ 3.560905] ima: Allocated hash algorithm: sha1 [ 3.562076] ima: No architecture policies found [ 3.564259] evm: Initialising EVM extended attributes: [ 3.566181] evm: security.selinux [ 3.566959] evm: security.ima [ 3.567724] evm: security.capability [ 3.568636] evm: HMAC attrs: 0x1 [ 3.570315] rtc_cmos 00:05: setting system clock to 2026-03-02 16:56:45 UTC (1772470605) [ 3.574517] debug: unmapping init [mem 0xffffffff97403000-0xffffffff975fffff] [ 3.576644] debug: unmapping init [mem 0xffffffff96182000-0xffffffff96458fff] [ 3.582207] Write protecting the kernel read-only data: 28672k [ 3.584717] debug: unmapping init [mem 0xffffffff94803000-0xffffffff949fffff] [ 3.586676] debug: unmapping init [mem 0xffffffff95114000-0xffffffff951fffff] [ 3.635643] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.642679] systemd[1]: Detected virtualization kvm. [ 3.644693] systemd[1]: Detected architecture x86-64. [ 3.647705] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.671225] systemd[1]: No hostname configured. [ 3.672555] systemd[1]: Set hostname to . [ 3.674326] random: systemd: uninitialized urandom read (16 bytes read) [ 3.676246] systemd[1]: Initializing machine ID from random generator. [ 3.722050] random: ln: uninitialized urandom read (6 bytes read) [ 3.796349] random: systemd: uninitialized urandom read (16 bytes read) [ 3.798421] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.805199] systemd[1]: Starting Create list of required static device nodes for the current kernel... Starting Create list of required st…ce nodes for the current kernel... [ 3.811263] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Memstrack Anylazing Service. Starting Setup Virtual Console... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Swap. Starting Apply Kernel Variables... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Slices. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.384230] device-mapper: uevent: version 1.0.3 [ 4.386233] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.087657] random: fast init done [ 5.094803] virtio_net virtio0 ens2: renamed from eth0 [ 5.181460] scsi host0: ata_piix [ 5.190835] scsi host1: ata_piix [ 5.232342] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.235064] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.922574] dracut-initqueue[582]: RTNETLINK answers: File exists [ 10.090903] random: crng init done [ 10.102304] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 11.363380] 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 dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Swap. [ 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 udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 14.312693] printk: systemd: 25 output lines suppressed due to ratelimiting [ 15.337885] SELinux: Disabled at runtime. [ 15.485190] 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) [ 15.497460] systemd[1]: Detected virtualization kvm. [ 15.499682] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 17.157408] systemd[1]: initrd-switch-root.service: Succeeded. [ 17.163889] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 17.171505] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 17.188583] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 17.197088] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 17.218549] systemd[1]: Starting Journal Service... Starting Journal Service... [ 17.223699] systemd[1]: Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on Process Core Dump Socket. [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 ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting POSIX Message Queue File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. Activating swap /dev/disk/by-label/SWAP... Starting Remount Root and Kernel File Systems... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ 17.583359] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. Mounting Huge Pages File System... Mounting Kernel Debug File System... [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Listening on initctl Compatibility Named Pipe. Starting Create list of required st…ce nodes for the current kernel... [ 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 ] Created slice system-getty.slice. Starting Apply Kernel Variables... [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [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 ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 18.957533] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 20.003785] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 20.154339] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 20.506480] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 20.675881] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit)[ 25.341808] Key type dns_resolver registered [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 25.922428] NFS: Registering the id_resolver key type [ 25.924347] Key type id_resolver registered [ 25.925751] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ 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 ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. [ OK ] Reached target sshd-keygen.target. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg113-server login: [ 69.678029] hrtimer: interrupt took 4016667 ns [ 81.721585] libcfs: loading out-of-tree module taints kernel. [ 81.785224] Key type ._llcrypt registered [ 81.787427] Key type .llcrypt registered [ 81.965663] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_hostid [ 100.373615] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 102.518034] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 102.551356] alg: No test for adler32 (adler32-zlib) [ 103.878403] Lustre: Lustre: Build Version: 2.17.50_196_gee1d501 [ 104.467079] LNet: Added LNI 192.168.201.113@tcp [8/256/0/180] [ 106.159644] Key type lgssc registered [ 107.704652] Lustre: Echo OBD driver; http://www.lustre.org/ [ 128.680001] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 170.600076] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 182.259438] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 182.284496] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 183.650447] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 183.723354] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 183.918887] Lustre: lustre-MDT0000: new disk, initializing [ 184.099735] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 184.166816] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 189.443499] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 204.902569] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 205.051950] Lustre: 6506: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 [ 205.104547] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 205.108883] Lustre: Skipped 1 previous similar message [ 205.236522] Lustre: lustre-MDT0001: new disk, initializing [ 205.368497] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 205.419512] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 205.427108] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 210.564116] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 215.614514] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 227.078729] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 227.289212] Lustre: lustre-OST0000: new disk, initializing [ 227.292638] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 227.366125] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 227.701294] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 227.714223] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 227.854319] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 235.851960] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 252.168325] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 252.331602] Lustre: lustre-OST0001: new disk, initializing [ 252.335794] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 252.403568] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 259.321573] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 262.706560] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 262.713496] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 262.822056] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 273.192897] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 283.697902] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 296.161236] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing check_logdir /tmp/testlogs/ [ 300.903919] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing yml_node [ 305.085899] Lustre: DEBUG MARKER: Client: 2.17.50.196 [ 307.961988] Lustre: DEBUG MARKER: MDS: 2.17.50.196 [ 310.474920] Lustre: DEBUG MARKER: OSS: 2.17.50.196 [ 312.145401] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Mon Mar 2 12:01:52 EST 2026 [ 333.486515] Lustre: DEBUG MARKER: excepting tests: [ 351.726174] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 364.515344] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 364.525704] 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 [ 364.557518] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 365.547523] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 365.548546] 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 [ 365.572870] Lustre: Skipped 1 previous similar message [ 365.602163] Lustre: Skipped 2 previous similar messages [ 369.540916] Lustre: server umount lustre-MDT0000 complete [ 375.777193] LustreError: 6514: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. [ 375.809809] LustreError: 6514:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 378.186418] LustreError: 8423:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772470980 with bad export cookie 6528108178273310133 [ 378.187964] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 378.194796] LustreError: 8423:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 378.620357] Lustre: server umount lustre-MDT0001 complete [ 397.087210] Lustre: 3660:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772470982/real 1772470982] req@ffff915502d29880 x1858570243128192/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772470998 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 397.126844] 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 [ 398.269575] Lustre: server umount lustre-OST0000 complete [ 399.393712] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772470985/real 1772470985] req@ffff915502d2aa00 x1858570243128448/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471001 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 401.375502] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772470987/real 1772470987] req@ffff91562e504e00 x1858570243128704/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471003 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 405.602328] Lustre: 3658:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772470991/real 1772470991] req@ffff915502bd0e00 x1858570243129088/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471007 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 410.079830] Lustre: 3657:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772470996/real 1772470996] req@ffff91562e507100 x1858570243129216/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471012 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 410.446906] Lustre: server umount lustre-OST0001 complete [ 429.927101] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing unload_modules_local [ 433.852822] Key type lgssc unregistered [ 434.132548] LNet: 14744:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 434.144649] LNetError: 14744:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 434.158266] LNet: Removed LNI 192.168.201.113@tcp [ 435.289151] Key type .llcrypt unregistered [ 435.290989] Key type ._llcrypt unregistered [ 461.430403] Key type ._llcrypt registered [ 461.432733] Key type .llcrypt registered [ 461.610646] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_hostid [ 479.336137] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 480.542507] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 480.654389] alg: No test for adler32 (adler32-zlib) [ 481.710695] Lustre: Lustre: Build Version: 2.17.50_196_gee1d501 [ 481.988567] LNet: Added LNI 192.168.201.113@tcp [8/256/0/180] [ 483.759187] Key type lgssc registered [ 485.028894] Lustre: Echo OBD driver; http://www.lustre.org/ [ 532.021588] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 544.627086] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 544.654272] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 546.046960] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 546.120911] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 546.300518] Lustre: lustre-MDT0000: new disk, initializing [ 546.479266] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 546.511363] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 550.391325] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 565.926592] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 566.049175] Lustre: 19148: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 [ 566.096202] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 566.104448] Lustre: Skipped 1 previous similar message [ 566.191924] Lustre: lustre-MDT0001: new disk, initializing [ 566.301834] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 566.342227] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 566.357764] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 570.356220] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 575.467680] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 586.334185] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 586.617523] Lustre: lustre-OST0000: new disk, initializing [ 586.622361] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 586.689282] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 590.883279] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 590.890044] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 590.973499] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 592.304926] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 605.776686] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 605.858753] Lustre: lustre-OST0001: new disk, initializing [ 605.862249] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 605.931792] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 612.481197] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 613.455346] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 613.469553] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 613.527304] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 623.427746] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 629.252801] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 643.861274] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 12:07:23 (1772471243) === [ 645.563084] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 12:07:25 (1772471245) [ 666.919700] Lustre: Failing over lustre-MDT0000 [ 667.368282] Lustre: server umount lustre-MDT0000 complete [ 668.640164] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 668.647055] 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 [ 670.177473] 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 [ 670.194894] Lustre: Skipped 2 previous similar messages [ 670.970529] Lustre: Failing over lustre-MDT0001 [ 670.982502] LustreError: 19141:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471272 with bad export cookie 13666801401579062486 [ 670.999307] LustreError: 19141:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 671.000570] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 671.471321] Lustre: server umount lustre-MDT0001 complete [ 680.767436] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 691.488209] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471277/real 1772471277] req@ffff915502f59500 x1858570638459904/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471293 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 691.519973] 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 [ 695.647758] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9155019a9c00 x1858570638461440/t0(0) o250->MGC192.168.201.113@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 [ 695.937399] LustreError: 21048: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. [ 695.951354] LustreError: 21048:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 696.061934] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 696.110201] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 696.993081] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471282/real 1772471282] req@ffff915502ef4000 x1858570638460288/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471298 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 697.031131] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 700.833607] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 701.158088] LustreError: 24070: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. [ 701.193853] LustreError: 24070:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 701.791165] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471287/real 1772471287] req@ffff915502ef7480 x1858570638460416/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471303 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 701.826495] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 706.145708] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471292/real 1772471292] req@ffff9155019ab480 x1858570638461056/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471308 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 706.168099] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 706.527835] LustreError: 24071: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. [ 708.782800] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 708.998231] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 709.014141] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 709.078930] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 709.119026] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 709.119724] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 710.125804] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 710.160537] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 710.201333] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 710.202190] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 713.657542] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 727.579987] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 12:08:47 (1772471327) [ 752.445164] Lustre: Failing over lustre-MDT0000 [ 752.863971] Lustre: server umount lustre-MDT0000 complete [ 755.176814] 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 [ 755.187868] LustreError: 21048: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. [ 755.203528] Lustre: Skipped 2 previous similar messages [ 755.224996] LustreError: 21048:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 756.951140] Lustre: Failing over lustre-MDT0001 [ 756.951337] LustreError: 19140:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471358 with bad export cookie 13666801401579078992 [ 756.952614] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 756.991652] LustreError: 19140:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 757.287085] Lustre: server umount lustre-MDT0001 complete [ 765.950057] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 766.440241] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7704eef183 [ 766.455587] Lustre: MGC192.168.201.113@tcp: Connection restored to 0@lo (at 0@lo) [ 766.467652] Lustre: Skipped 4 previous similar messages [ 766.769410] LustreError: 25551: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. [ 766.928988] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 766.973893] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 770.782315] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 772.063715] 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 [ 772.075648] Lustre: Skipped 2 previous similar messages [ 775.137109] LustreError: 26433: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. [ 775.152313] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 775.175093] LustreError: 26433:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 776.163820] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471362/real 1772471362] req@ffff91563748d180 x1858570638581760/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471378 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 776.220555] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 779.500931] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 779.760392] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 779.895679] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 779.908938] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 784.093486] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 785.377462] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 785.382983] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 785.399042] Lustre: Skipped 1 previous similar message [ 785.424219] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 785.482679] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 785.487428] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 788.667231] Lustre: *** cfs_fail_loc=193, val=0*** [ 794.444539] Lustre: Failing over lustre-MDT0000 [ 794.708302] Lustre: server umount lustre-MDT0000 complete [ 795.618248] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 795.629880] 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 [ 795.646264] Lustre: Skipped 2 previous similar messages [ 795.650672] LustreError: 26432: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. [ 795.674627] LustreError: 26432:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 804.570574] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 804.711990] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 804.952648] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 804.966185] Lustre: Skipped 1 previous similar message [ 804.997536] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 809.431314] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 809.955340] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 809.969709] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 809.997860] Lustre: Skipped 2 previous similar messages [ 810.023333] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 810.075418] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 810.080811] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 820.166509] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 12:10:20 (1772471420) [ 835.630528] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 856.172756] Lustre: 30259:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 885.078951] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 890.538662] Lustre: 31396:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 912.473302] Lustre: *** cfs_fail_loc=198, val=0*** [ 925.441434] Lustre: Failing over lustre-MDT0000 [ 925.963588] Lustre: server umount lustre-MDT0000 complete [ 927.714438] 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 [ 927.718898] LustreError: 26431: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. [ 927.733456] Lustre: Skipped 3 previous similar messages [ 927.739359] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 927.748105] LustreError: 26431:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 930.252878] LustreError: 22812:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471532 with bad export cookie 13666801401579108252 [ 930.273837] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 930.276610] LustreError: 22812:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 930.295993] Lustre: Failing over lustre-MDT0001 [ 930.654446] Lustre: server umount lustre-MDT0001 complete [ 935.849631] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 940.692851] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 948.142154] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471534/real 1772471534] req@ffff91563fbc1f80 x1858570638764672/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471550 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 948.195848] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 949.804949] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 955.423619] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91563387e680 x1858570638766848/t0(0) o250->MGC192.168.201.113@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 [ 955.787657] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 955.820777] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 960.074387] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 965.087275] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471550/real 1772471550] req@ffff91563f43c000 x1858570638766592/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471566 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 965.111774] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 10 previous similar messages [ 967.144219] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 967.148886] Lustre: Skipped 3 previous similar messages [ 967.625926] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 967.808956] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 967.965148] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 967.965601] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:171 to 0x280000400:193) [ 972.223436] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 973.284704] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 973.331116] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 973.406509] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 973.411370] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:203 to 0x280000401:225) [ 987.026467] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 12:13:07 (1772471587) [ 1010.553669] Lustre: Failing over lustre-MDT0000 [ 1010.805723] Lustre: server umount lustre-MDT0000 complete [ 1014.246355] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1014.261696] 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 [ 1014.266167] LustreError: 32878: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. [ 1014.280667] Lustre: Skipped 6 previous similar messages [ 1014.323112] LustreError: 32878:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 1014.710157] Lustre: Failing over lustre-MDT0001 [ 1014.711122] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471616 with bad export cookie 13666801401579136014 [ 1014.714271] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1014.732347] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1015.175722] Lustre: server umount lustre-MDT0001 complete [ 1019.893317] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1024.654882] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1033.152490] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1033.186656] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 1035.746988] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471621/real 1772471621] req@ffff915637ed9f80 x1858570638890112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471637 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1040.398587] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1047.168227] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1054.701755] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1054.710882] Lustre: Skipped 4 previous similar messages [ 1057.268454] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1057.330280] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1057.575694] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1057.800786] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 1057.809726] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 1062.893562] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1062.927848] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1062.937404] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1063.008713] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 1063.015545] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1088.877055] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 1111.276403] Lustre: 38623:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1138.151366] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1142.190806] Lustre: 39760:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1170.508128] Lustre: Failing over lustre-MDT0000 [ 1170.778515] Lustre: server umount lustre-MDT0000 complete [ 1174.579066] LustreError: 25564:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471776 with bad export cookie 13666801401579164161 [ 1174.581593] Lustre: Failing over lustre-MDT0001 [ 1174.582567] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1174.595943] LustreError: 25564:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1175.072816] Lustre: server umount lustre-MDT0001 complete [ 1181.134422] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1189.692462] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1191.720887] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772471777/real 1772471777] req@ffff915637c52d80 x1858570639048320/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772471793 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1191.721290] 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 [ 1191.754090] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 1191.786482] Lustre: Skipped 5 previous similar messages [ 1203.066541] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1203.124972] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1219.984849] LustreError: 21048: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. [ 1220.015366] LustreError: 21048:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 1220.239138] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1220.241947] Lustre: Skipped 3 previous similar messages [ 1220.301819] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1226.444444] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1236.870311] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1236.916528] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1236.964839] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1236.981727] Lustre: Skipped 4 previous similar messages [ 1237.177648] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1237.352171] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:298 to 0x280000400:321) [ 1237.352431] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1242.323304] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1242.610245] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1242.689662] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1242.746755] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1242.752456] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 1270.682468] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 1291.307465] Lustre: 44428:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1317.232769] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1322.119075] Lustre: 45565:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1351.163973] Lustre: Failing over lustre-MDT0000 [ 1351.452647] Lustre: server umount lustre-MDT0000 complete [ 1355.132869] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772471957 with bad export cookie 13666801401579192126 [ 1355.136654] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1355.136904] Lustre: Failing over lustre-MDT0001 [ 1355.154241] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1355.240759] 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 [ 1355.244533] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1355.255819] Lustre: Skipped 3 previous similar messages [ 1355.278319] Lustre: Skipped 1 previous similar message [ 1355.567879] Lustre: server umount lustre-MDT0001 complete [ 1360.946632] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1368.748806] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1381.729905] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1381.868266] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1400.291419] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff915634e95180 x1858570639209600/t0(0) o250->MGC192.168.201.113@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 [ 1400.747293] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1406.558470] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1416.460613] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1416.518570] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1416.695452] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1416.842866] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1416.852589] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1420.913369] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1420.917298] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1420.941727] Lustre: Skipped 4 previous similar messages [ 1420.979767] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1421.033375] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1421.034353] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 1421.889365] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1439.356244] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 12:20:39 (1772472039) [ 1457.164412] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 1477.847694] Lustre: 50236:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1501.988945] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1533.388301] Lustre: Failing over lustre-MDT0000 [ 1533.620476] Lustre: server umount lustre-MDT0000 complete [ 1533.922130] LustreError: 25551: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. [ 1533.935430] LustreError: 25551:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 16 previous similar messages [ 1537.316530] Lustre: Failing over lustre-MDT0001 [ 1537.317452] LustreError: 19140:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772472139 with bad export cookie 13666801401579220091 [ 1537.318296] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1537.352367] LustreError: 19140:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1537.714282] Lustre: server umount lustre-MDT0001 complete [ 1543.453483] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1553.712318] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1554.400789] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772472140/real 1772472140] req@ffff91563367c700 x1858570639363968/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772472156 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1554.424720] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 15 previous similar messages [ 1562.698093] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1572.134704] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1583.662093] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1583.687792] Lustre: lustre-MDT0000: reset Object Index mappings [ 1607.724320] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7704f119b8 [ 1607.745397] Lustre: MGC192.168.201.113@tcp: Connection restored to 0@lo (at 0@lo) [ 1607.758500] Lustre: Skipped 4 previous similar messages [ 1608.184730] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1608.186777] Lustre: Skipped 3 previous similar messages [ 1608.224227] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1614.016480] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1625.271271] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1625.301573] Lustre: lustre-MDT0001: reset Object Index mappings [ 1625.746289] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:426 to 0x2c0000400:449) [ 1625.749714] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1631.202598] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1631.255565] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1631.323972] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1631.324399] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1631.525762] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1644.176930] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 12:24:04 (1772472244) [ 1669.222779] Lustre: Failing over lustre-MDT0000 [ 1669.652146] Lustre: server umount lustre-MDT0000 complete [ 1672.160807] 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 [ 1672.168900] Lustre: Skipped 10 previous similar messages [ 1673.537839] Lustre: Failing over lustre-MDT0001 [ 1673.541859] LustreError: 22812:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772472275 with bad export cookie 13666801401579248056 [ 1673.542893] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1673.553229] LustreError: 22812:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1674.000978] Lustre: server umount lustre-MDT0001 complete [ 1679.326451] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1688.656831] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1698.174606] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1709.760996] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1722.092242] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1722.115881] Lustre: lustre-MDT0000: reset Object Index mappings [ 1743.839886] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91562fbd2a00 x1858570639486080/t0(0) o250->MGC192.168.201.113@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 [ 1744.643105] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1750.919289] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1760.882762] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1760.896465] Lustre: lustre-MDT0001: reset Object Index mappings [ 1761.219177] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1761.235548] LustreError: Skipped 2 previous similar messages [ 1761.462286] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1761.464609] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1762.412052] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1762.481493] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1762.548690] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1762.556240] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1766.559340] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1774.198851] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64025: rc = 0 [ 1775.354513] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32029 with flags 0x52: rc = 0 [ 1797.690617] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 12:26:37 (1772472397) [ 1823.565448] Lustre: Failing over lustre-MDT0000 [ 1823.843665] Lustre: server umount lustre-MDT0000 complete [ 1827.334306] Lustre: Failing over lustre-MDT0001 [ 1827.334815] LustreError: 25564:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772472429 with bad export cookie 13666801401579275552 [ 1827.336618] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1827.361527] LustreError: 25564:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1827.930675] Lustre: server umount lustre-MDT0001 complete [ 1833.571740] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1843.877537] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1846.752108] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772472432/real 1772472432] req@ffff915633634e00 x1858570639612288/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772472448 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1846.779503] Lustre: 16328:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 1853.905900] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1865.029970] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1881.260329] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1881.299872] Lustre: lustre-MDT0000: reset Object Index mappings [ 1898.016269] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91561eb5bb80 x1858570639616000/t0(0) o250->MGC192.168.201.113@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 [ 1898.643703] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1904.000952] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1912.711924] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1912.731845] Lustre: lustre-MDT0001: reset Object Index mappings [ 1913.057563] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1913.107765] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 1913.117800] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1915.117539] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1915.125510] Lustre: Skipped 10 previous similar messages [ 1915.151756] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 1915.210335] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1915.210775] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 1918.156785] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1927.544755] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32023: rc = 0 [ 1930.810813] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32039 with flags 0x52: rc = 0 [ 2054.765972] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 12:30:54 (1772472654) [ 2092.527572] Lustre: Failing over lustre-MDT0000 [ 2094.565735] LustreError: 21049: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. [ 2094.581874] LustreError: 21049:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 23 previous similar messages [ 2094.879469] Lustre: server umount lustre-MDT0000 complete [ 2099.138050] LustreError: 19142:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772472701 with bad export cookie 13666801401579303307 [ 2099.138723] Lustre: Failing over lustre-MDT0001 [ 2099.139742] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2099.152666] LustreError: 19142:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2099.591661] Lustre: server umount lustre-MDT0001 complete [ 2105.281733] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2114.961640] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2124.173976] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2136.981983] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2152.522702] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2152.549076] Lustre: lustre-MDT0000: reset Object Index mappings [ 2169.311674] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff915637b37480 x1858570639816448/t0(0) o250->MGC192.168.201.113@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 [ 2169.652822] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2169.663659] Lustre: Skipped 5 previous similar messages [ 2169.704099] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2174.647366] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2184.528262] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2184.550274] Lustre: lustre-MDT0001: reset Object Index mappings [ 2184.954418] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 2184.956965] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 2185.952737] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2186.001213] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2186.053679] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 2186.056654] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2189.055826] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2197.929290] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32045: rc = 0 [ 2201.363864] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32002 with flags 0x52: rc = 0 [ 2298.014691] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 12:34:57 (1772472897) [ 2319.265272] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2319.267989] Lustre: Skipped 1 previous similar message [ 2319.787138] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2319.789084] Lustre: Skipped 27 previous similar messages [ 2320.794867] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2320.798072] Lustre: Skipped 221 previous similar messages [ 2341.726427] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 12:35:41 (1772472941) [ 2346.326437] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2346.328558] Lustre: Skipped 205 previous similar messages [ 2346.659021] LustreError: 31431:0:(osd_compat.c:736:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 263/3438945191 264/1141247344 [ 2361.216124] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 12:36:00 (1772472960) [ 2380.777877] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2380.793177] LustreError: Skipped 4 previous similar messages [ 2380.811689] 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 [ 2380.822704] Lustre: Skipped 14 previous similar messages [ 2380.833412] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2382.815758] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2382.823135] Lustre: Skipped 2 previous similar messages [ 2384.777568] Lustre: server umount lustre-MDT0000 complete [ 2389.487237] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772472991 with bad export cookie 13666801401579347841 [ 2389.498723] LustreError: 22813:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2393.056639] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2393.067767] Lustre: Skipped 2 previous similar messages [ 2396.061552] Lustre: server umount lustre-MDT0001 complete [ 2408.397057] Lustre: server umount lustre-OST0000 complete [ 2418.743198] Lustre: server umount lustre-OST0001 complete [ 2427.064820] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_hostid [ 2436.355915] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 2489.414204] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 2498.732586] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2499.100627] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2499.154645] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2499.305670] Lustre: lustre-MDT0000: new disk, initializing [ 2499.522432] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2505.380965] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2519.568947] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2519.830792] Lustre: 75292: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 [ 2519.859407] Lustre: 75292:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 2519.931196] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2519.939863] Lustre: Skipped 1 previous similar message [ 2520.231891] Lustre: lustre-MDT0001: new disk, initializing [ 2520.545816] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2520.588665] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2526.306225] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2532.103257] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2539.304904] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2539.532238] Lustre: lustre-OST0000: new disk, initializing [ 2539.535182] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2541.350783] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2541.366466] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2541.474428] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2547.785333] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2560.677535] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2560.835570] Lustre: lustre-OST0001: new disk, initializing [ 2560.842054] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2562.581613] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2562.599984] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2562.706175] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2567.787535] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2578.072838] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2582.075866] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2612.439340] Lustre: Failing over lustre-MDT0000 [ 2614.702301] Lustre: server umount lustre-MDT0000 complete [ 2618.854863] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2618.855556] LustreError: 16326:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff915603491500 x1858570640149760/t0(0) o38->lustre-MDT0000-lwp-MDT0001@0@lo:12/10 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 [ 2618.861459] LustreError: Skipped 1 previous similar message [ 2618.893727] Lustre: Failing over lustre-MDT0001 [ 2619.249251] Lustre: server umount lustre-MDT0001 complete [ 2625.737062] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2639.079458] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772473225/real 1772473225] req@ffff91563f28d880 x1858570640151296/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772473241 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2639.125752] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 2639.691743] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2650.365027] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2660.521335] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2673.170898] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2673.207594] Lustre: lustre-MDT0000: reset Object Index mappings [ 2689.507197] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91563da84e00 x1858570640154240/t0(0) o250->MGC192.168.201.113@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 [ 2690.262965] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2693.307511] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2693.316210] Lustre: Skipped 9 previous similar messages [ 2694.568269] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2698.721314] LustreError: 76882: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. [ 2698.737839] LustreError: 76882:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 25 previous similar messages [ 2703.426068] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2703.879302] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2703.883212] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2707.539710] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2708.976257] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2709.019070] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2709.074961] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2709.077152] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2717.507491] Lustre: *** cfs_fail_loc=190, val=3*** [ 2717.507779] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32027: rc = 0 [ 2718.564493] Lustre: *** cfs_fail_loc=190, val=3*** [ 2718.566516] Lustre: Skipped 1 previous similar message [ 2719.623075] Lustre: *** cfs_fail_loc=190, val=3*** [ 2720.740713] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 2722.663156] Lustre: *** cfs_fail_loc=190, val=3*** [ 2722.671857] Lustre: Skipped 2 previous similar messages [ 2726.815112] Lustre: *** cfs_fail_loc=190, val=3*** [ 2726.816583] Lustre: Skipped 2 previous similar messages [ 2733.920856] Lustre: Failing over lustre-MDT0000 [ 2734.298608] Lustre: server umount lustre-MDT0000 complete [ 2738.129686] Lustre: Failing over lustre-MDT0001 [ 2738.635475] Lustre: server umount lustre-MDT0001 complete [ 2748.874951] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2768.480342] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2777.893946] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2778.297645] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2778.307283] Lustre: Skipped 8 previous similar messages [ 2778.361365] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 2778.364576] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2783.022784] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2783.800405] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2783.810546] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2788.700916] Lustre: Failing over lustre-MDT0000 [ 2788.986297] Lustre: server umount lustre-MDT0000 complete [ 2792.525977] Lustre: Failing over lustre-MDT0001 [ 2792.734643] Lustre: server umount lustre-MDT0001 complete [ 2803.295110] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2803.365096] Lustre: *** cfs_fail_loc=190, val=3*** [ 2803.366854] Lustre: Skipped 2 previous similar messages [ 2817.442041] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7704f467fb [ 2821.535174] Lustre: *** cfs_fail_loc=190, val=3*** [ 2821.536991] Lustre: Skipped 5 previous similar messages [ 2822.196814] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2830.877972] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2831.208909] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 2831.217155] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2835.111971] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2836.532377] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2836.539792] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2847.600038] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x46:0x0]/201: rc = 0 [ 2847.600914] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 2857.167618] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 12:44:17 (1772473457) [ 2883.188338] Lustre: Failing over lustre-MDT0000 [ 2883.687859] Lustre: server umount lustre-MDT0000 complete [ 2886.883696] Lustre: Failing over lustre-MDT0001 [ 2887.379309] Lustre: server umount lustre-MDT0001 complete [ 2891.967215] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2900.086438] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2905.956977] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2913.605202] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2922.815894] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2922.839402] Lustre: lustre-MDT0000: reset Object Index mappings [ 2922.841601] Lustre: Skipped 1 previous similar message [ 2931.488920] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91561084ca80 x1858570640338304/t0(0) o250->MGC192.168.201.113@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 [ 2934.689888] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2939.924701] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2940.185501] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2940.190169] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 2942.484658] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2945.138437] Lustre: lustre-MDT0000: Denying connection for new client 46e2f546-e23a-4cb9-9d7a-2c27a512f009 (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2945.541595] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 2945.541628] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2953.057020] Lustre: *** cfs_fail_loc=190, val=2*** [ 2953.061601] Lustre: Skipped 11 previous similar messages [ 2953.062218] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/64001: rc = 0 [ 2956.237538] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2976.915821] Lustre: Failing over lustre-MDT0000 [ 2977.045349] Lustre: server umount lustre-MDT0000 complete [ 2978.871980] LustreError: 75283:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772473580 with bad export cookie 13666801401579506461 [ 2978.876536] Lustre: Failing over lustre-MDT0001 [ 2978.881445] LustreError: 75283:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 2979.069654] Lustre: server umount lustre-MDT0001 complete [ 2985.102931] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2988.513729] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7704f5127f [ 2991.542056] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2994.146737] 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 [ 2994.155047] Lustre: Skipped 29 previous similar messages [ 2996.423937] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2996.536629] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2996.543645] LustreError: Skipped 7 previous similar messages [ 2996.595743] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2996.602328] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 2998.725959] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3001.909963] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 3001.912156] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 3012.301540] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 12:46:53 (1772473613) [ 3021.300654] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 3032.940623] Lustre: 95799:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3047.551526] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3049.626570] Lustre: 96933:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3081.936678] Lustre: Failing over lustre-MDT0000 [ 3082.113298] Lustre: server umount lustre-MDT0000 complete [ 3084.495594] Lustre: Failing over lustre-MDT0001 [ 3084.729659] Lustre: server umount lustre-MDT0001 complete [ 3088.477308] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3095.272895] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3100.916841] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3107.623094] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3114.430415] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3129.825107] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff915608573b80 x1858570640517632/t0(0) o250->MGC192.168.201.113@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 [ 3133.010921] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3138.719765] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3139.020732] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 3139.021138] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 3141.225980] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3143.528161] Lustre: lustre-MDT0000: Denying connection for new client 7eb96f4f-7cb0-4d58-8735-625b879ba1a9 (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 3144.204600] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3144.204883] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 3151.407543] Lustre: *** cfs_fail_loc=190, val=3*** [ 3151.407990] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32043: rc = 0 [ 3151.412029] Lustre: Skipped 30 previous similar messages [ 3151.422862] Lustre: Skipped 2 previous similar messages [ 3153.579973] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32026 with flags 0x52: rc = 0 [ 3168.679406] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 12:49:29 (1772473769) [ 3195.335068] Lustre: Failing over lustre-MDT0000 [ 3195.366551] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3195.369889] Lustre: Skipped 5 previous similar messages [ 3195.583518] Lustre: server umount lustre-MDT0000 complete [ 3197.665570] Lustre: Failing over lustre-MDT0001 [ 3197.829991] Lustre: server umount lustre-MDT0001 complete [ 3200.954366] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3205.862870] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3210.323924] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3215.766060] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3221.719208] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3221.728559] Lustre: lustre-MDT0000: reset Object Index mappings [ 3221.730966] Lustre: Skipped 3 previous similar messages [ 3222.815247] LustreError: 104682:0:(import.c:337:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 3222.822872] LustreError: 104682:0:(import.c:361:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff915610849f80 x1858570640647424/t0(0) o250->MGC192.168.201.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1772473824 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3222.833589] LustreError: 104682:0:(import.c:371:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 3225.470921] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3230.625125] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3230.855495] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3230.855622] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 3233.059210] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3236.022500] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 3236.026488] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3258.051195] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 12:50:59 (1772473859) [ 3265.212388] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 3274.888826] Lustre: 108435:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3288.434983] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3378.838668] Lustre: Failing over lustre-MDT0000 [ 3379.224758] Lustre: server umount lustre-MDT0000 complete [ 3379.685603] LustreError: 100998: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. [ 3379.698251] LustreError: 100998:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 49 previous similar messages [ 3381.455915] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3381.459160] Lustre: Failing over lustre-MDT0001 [ 3381.461771] LustreError: Skipped 6 previous similar messages [ 3381.870913] Lustre: server umount lustre-MDT0001 complete [ 3385.322529] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3392.633172] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3400.019341] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3400.159406] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772473986/real 1772473986] req@ffff91560448c700 x1858570640812800/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772474002 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3400.182859] Lustre: 16329:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 85 previous similar messages [ 3406.800209] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3415.098596] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3426.847450] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91560448f800 x1858570640815872/t0(0) o250->MGC192.168.201.113@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 [ 3426.859839] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 3427.121393] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3427.124601] Lustre: Skipped 10 previous similar messages [ 3427.161378] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3427.166880] Lustre: Skipped 6 previous similar messages [ 3429.389396] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3434.420200] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3434.639252] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 3434.647432] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 3437.331626] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3440.098440] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3440.102089] Lustre: Skipped 6 previous similar messages [ 3440.123708] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3440.123782] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3440.128083] Lustre: Skipped 6 previous similar messages [ 3440.139776] Lustre: Skipped 36 previous similar messages [ 3440.155806] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3440.167302] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 3487.005393] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 12:54:47 (1772474087) [ 3495.844467] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 3507.045759] Lustre: 116336:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3507.051429] Lustre: 116336:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 3520.597362] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3652.565704] Lustre: Failing over lustre-MDT0000 [ 3652.725994] Lustre: server umount lustre-MDT0000 complete [ 3654.646888] LustreError: 87401:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772474256 with bad export cookie 13666801401579859828 [ 3654.648372] Lustre: Failing over lustre-MDT0001 [ 3654.654033] LustreError: 87401:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 14 previous similar messages [ 3654.833630] Lustre: server umount lustre-MDT0001 complete [ 3657.631136] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3662.711303] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3666.553203] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3670.470398] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3672.031192] 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 [ 3672.036684] Lustre: Skipped 21 previous similar messages [ 3674.933518] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3680.893124] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3684.901723] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3685.025095] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 3685.031070] LustreError: Skipped 6 previous similar messages [ 3685.100213] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 3685.100395] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 3687.302726] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3689.243703] Lustre: lustre-MDT0000: Denying connection for new client f07088be-6bd1-4a33-ac17-69a66197d6f8 (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 3690.510053] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 3690.510234] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 3696.453920] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32003: rc = 0 [ 3696.453940] Lustre: *** cfs_fail_loc=190, val=1*** [ 3696.460924] Lustre: Skipped 33 previous similar messages [ 3699.596338] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32005 with flags 0x52: rc = 0 [ 3703.268190] Lustre: Failing over lustre-MDT0000 [ 3703.375293] Lustre: server umount lustre-MDT0000 complete [ 3705.042950] Lustre: Failing over lustre-MDT0001 [ 3705.156603] Lustre: server umount lustre-MDT0001 complete [ 3708.602178] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3714.529716] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff915604badf80 x1858570641039488/t0(0) o250->MGC192.168.201.113@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 [ 3714.544513] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 3716.784692] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3721.317943] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3721.539906] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 3721.542916] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 3723.514701] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3726.674507] Lustre: Failing over lustre-MDT0000 [ 3726.683268] LustreError: 122288:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 3726.689454] LustreError: 122288:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 3726.692440] LustreError: 122288:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 12, retries 0, failed: rc = -5 [ 3726.695811] Lustre: 122289:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3726.696046] LustreError: 123518:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3726.701486] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 3726.712967] LustreError: 122289:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff91563dc22a00 x1858570641056256/t0(0) o1000->lustre-MDT0001-osp-MDT0000@0@lo:24/4 lens 304/4320 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 3726.721129] LustreError: 122289:0:(lod_dev.c:350:lod_sub_recreate_llog()) lustre-MDT0000-mdtlov: can't access update_log: rc = -5 [ 3726.882095] Lustre: server umount lustre-MDT0000 complete [ 3728.675297] Lustre: Failing over lustre-MDT0001 [ 3728.677221] LustreError: 122994:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200000009:0x0:0x0]: rc = -5 [ 3728.682350] LustreError: 122994:0:(osp_object.c:617:osp_attr_get()) Skipped 1 previous similar message [ 3728.686234] LustreError: 122994:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0001-mdtlov: can't get id from catalogs: rc = -5 [ 3728.689955] LustreError: 122994:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 7, retries 0, failed: rc = -5 [ 3728.852380] Lustre: server umount lustre-MDT0001 complete [ 3732.968088] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3738.081216] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7705052918 [ 3739.739461] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3743.731465] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3743.931772] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 3743.935253] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 3745.653984] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3747.003798] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 3747.004684] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 3753.219211] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 12:59:14 (1772474354) [ 3759.294580] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 3768.536521] Lustre: 127229:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3768.540177] Lustre: 127229:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 3779.621139] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3799.558961] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 13:00:00 (1772474400) [ 3801.628520] Lustre: *** cfs_fail_loc=195, val=0*** [ 3803.149095] Lustre: Failing over lustre-OST0000 [ 3803.213773] Lustre: server umount lustre-OST0000 complete [ 3807.084296] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3809.759918] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3992.917449] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 13:03:14 (1772474594) [ 3994.298140] Lustre: *** cfs_fail_loc=196, val=0*** [ 3994.300200] Lustre: Skipped 63 previous similar messages [ 3995.816867] Lustre: Failing over lustre-OST0000 [ 3995.859330] Lustre: server umount lustre-OST0000 complete [ 3996.640547] LustreError: 96964: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. [ 3996.646514] LustreError: 96964:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 21 previous similar messages [ 3998.838651] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4000.857169] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4193.506694] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 13:06:34 (1772474794) [ 4195.445316] Lustre: *** cfs_fail_loc=196, val=0*** [ 4195.448874] Lustre: Skipped 63 previous similar messages [ 4197.485956] Lustre: *** cfs_fail_loc=196, val=0*** [ 4197.488840] Lustre: Skipped 671 previous similar messages [ 4200.392402] Lustre: Failing over lustre-OST0000 [ 4200.415918] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 4200.418655] Lustre: Skipped 1 previous similar message [ 4200.454587] Lustre: server umount lustre-OST0000 complete [ 4204.523544] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4204.616897] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4204.622580] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4204.626176] Lustre: Skipped 7 previous similar messages [ 4206.125405] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4206.128654] Lustre: Skipped 4 previous similar messages [ 4206.137541] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4206.137557] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4206.140401] Lustre: Skipped 4 previous similar messages [ 4206.144796] Lustre: Skipped 23 previous similar messages [ 4206.656049] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4213.215822] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4214.751594] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4214.754706] Lustre: Skipped 3 previous similar messages [ 4216.104832] Lustre: server umount lustre-MDT0000 complete [ 4217.319795] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4217.326463] LustreError: Skipped 3 previous similar messages [ 4217.436065] Lustre: server umount lustre-MDT0001 complete [ 4229.068813] Lustre: server umount lustre-OST0000 complete [ 4240.679201] Lustre: server umount lustre-OST0001 complete [ 4244.359755] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 13:07:25 (1772474845) [ 4249.661133] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_hostid [ 4252.110894] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4266.238091] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4269.654411] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4269.740214] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4269.754323] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4269.792480] Lustre: lustre-MDT0000: new disk, initializing [ 4269.822284] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4269.825602] Lustre: Skipped 9 previous similar messages [ 4269.832877] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4271.136990] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4275.278378] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4275.321255] Lustre: 138411: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 [ 4275.329060] Lustre: 138411:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 1 previous similar message [ 4275.342112] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4275.343972] Lustre: Skipped 1 previous similar message [ 4275.381030] Lustre: lustre-MDT0001: new disk, initializing [ 4275.407387] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4275.409972] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4276.716424] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4279.020658] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4281.173855] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4281.266379] Lustre: lustre-OST0000: new disk, initializing [ 4281.267863] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4282.413084] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4282.417261] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4282.441538] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4283.152783] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4287.138662] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4287.177614] Lustre: lustre-OST0001: new disk, initializing [ 4287.179466] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4288.683577] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4288.686564] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4288.697669] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4289.044945] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4293.408261] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4294.546788] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4306.239765] Lustre: Failing over lustre-MDT0000 [ 4306.400364] Lustre: server umount lustre-MDT0000 complete [ 4306.400390] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4306.404731] LustreError: Skipped 6 previous similar messages [ 4306.406545] 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 [ 4306.411841] Lustre: Skipped 19 previous similar messages [ 4307.655592] LustreError: 138405:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1772474909 with bad export cookie 13666801401580680963 [ 4307.656946] Lustre: Failing over lustre-MDT0001 [ 4307.659640] LustreError: 138405:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 4307.761340] Lustre: server umount lustre-MDT0001 complete [ 4309.581725] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4312.625104] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4315.434847] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4318.497569] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4322.201840] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4322.211953] Lustre: lustre-MDT0000: reset Object Index mappings [ 4322.214098] Lustre: Skipped 5 previous similar messages [ 4325.343165] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1772474911/real 1772474911] req@ffff91550a035180 x1858570641510528/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1772474927 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4325.352762] Lustre: 16327:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 51 previous similar messages [ 4332.511383] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff915611673100 x1858570641513344/t0(0) o250->MGC192.168.201.113@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 [ 4332.520330] LustreError: 16326:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 4333.858567] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4336.719604] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4336.834365] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 4336.834378] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 4338.059497] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4342.257959] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 4342.257974] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 4353.587140] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 13:09:14 (1772474954) [ 4357.696605] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4371.535113] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4386.174761] Lustre: Failing over lustre-MDT0000 [ 4386.186842] Lustre: *** cfs_fail_loc=199, val=0*** [ 4386.188284] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 4386.191530] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 4386.195199] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 4386.198172] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 4386.200694] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 4386.203238] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 4386.206539] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 4386.209168] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 4386.211704] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 4386.215028] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 4386.218520] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 4386.221838] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 4386.224438] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 4386.227877] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 4386.231440] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 4386.234242] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 4386.238379] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 4386.242240] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 4386.246578] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 4386.249395] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 4386.252780] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 4386.256324] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 4386.259835] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 4386.263262] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 4386.266601] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 4386.269979] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 4386.273498] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 4386.277210] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 4386.280915] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 4386.284454] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 4386.288096] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 4386.294124] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 4386.297909] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 4386.301870] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 4386.306515] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 4386.310582] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 4386.314901] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 4386.318310] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 4386.321137] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 4386.324111] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 4386.327476] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 4386.331424] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 4386.333911] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 4386.336512] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 4386.338886] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 4386.341255] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 4386.344549] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 4386.348603] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 4386.352098] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 4386.355500] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 4386.358936] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 4386.362364] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 4386.365957] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 4386.369420] Lustre: 150475:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 4386.469964] Lustre: server umount lustre-MDT0000 complete [ 4387.638910] Lustre: Failing over lustre-MDT0001 [ 4387.643425] Lustre: *** cfs_fail_loc=199, val=0*** [ 4387.644551] Lustre: Skipped 53 previous similar messages [ 4387.646256] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 4387.649360] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 4387.652250] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 4387.655388] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 4387.658480] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 4387.661573] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 4387.664846] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 4387.668039] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 4387.671052] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 4387.673975] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 4387.676821] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 4387.679575] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 4387.682436] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 4387.685224] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 4387.687976] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 4387.690697] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 4387.693493] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 4387.696245] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 4387.699294] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 4387.702086] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 4387.704900] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 4387.707583] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 4387.710296] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 4387.712987] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 4387.715885] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 4387.718644] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 4387.721414] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 4387.724223] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 4387.726928] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 4387.729604] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 4387.732363] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 4387.736070] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 4387.739794] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 4387.743202] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 4387.748504] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 4387.751465] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 4387.754303] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 4387.756961] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 4387.759739] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 4387.762460] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 4387.765810] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 4387.770112] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 4387.773675] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 4387.778175] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 4387.781601] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 4387.784542] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 4387.787617] Lustre: 150676:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 4387.899250] Lustre: server umount lustre-MDT0001 complete [ 4391.015298] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4391.048947] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 4391.052384] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 4391.055794] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 4391.059819] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 4391.063562] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 4391.068273] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 4391.071776] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 4391.076387] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 4391.080303] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 4391.084164] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 4391.087301] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 4391.090954] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 4391.095735] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 4391.101920] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 4391.108211] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 4391.113750] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 4391.117150] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 4391.120751] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 4391.124131] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 4391.127310] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 4391.131298] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 4391.137413] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 4391.143421] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 4391.149415] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 4391.155285] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 4391.158912] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 4391.163587] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 4391.167603] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 4391.171425] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 4391.177221] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 4391.182370] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 4391.190564] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 4391.196169] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 4391.201792] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 4391.205470] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 4391.211911] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 4391.219948] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 4391.223707] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 4391.227213] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 4391.231248] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 4391.235341] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 4391.240245] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 4391.243397] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 4391.246550] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 4391.249838] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 4391.254085] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 4391.257635] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 4391.261523] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 4391.265567] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 4391.269853] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 4391.273559] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 4391.277835] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 4391.282866] Lustre: 151172:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 4398.048343] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b770507b04b [ 4399.474628] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4402.182661] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4402.210040] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 4402.214793] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 4402.218969] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 4402.223847] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 4402.228435] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 4402.233193] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 4402.237092] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 4402.240480] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 4402.243773] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 4402.247259] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 4402.250781] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 4402.254451] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 4402.258975] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 4402.262338] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 4402.267263] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 4402.271370] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 4402.275121] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 4402.278584] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 4402.283368] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 4402.287528] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 4402.291271] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 4402.294908] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 4402.298710] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 4402.302523] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 4402.307410] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 4402.311503] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 4402.315233] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 4402.319258] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 4402.323031] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 4402.326517] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 4402.330233] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 4402.333973] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 4402.337808] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 4402.341441] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 4402.346503] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 4402.351986] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 4402.357360] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 4402.362469] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 4402.366316] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 4402.370926] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 4402.375720] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 4402.380350] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 4402.383931] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 4402.388145] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 4402.391849] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 4402.395588] Lustre: 151904:0:(osd_scrub.c:1831:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 4402.499290] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 4402.503902] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 4403.801291] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4404.521703] Lustre: lustre-MDT0000: Denying connection for new client 9bf223ab-1c2f-4aea-95aa-24722fb7d4fc (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 4407.800519] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 4407.800565] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 4412.067881] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 13:10:13 (1772475013) [ 4412.376933] Lustre: *** cfs_fail_loc=19d, val=0*** [ 4412.378021] Lustre: Skipped 123 previous similar messages [ 4412.972882] Lustre: Failing over lustre-MDT0000 [ 4413.121361] Lustre: server umount lustre-MDT0000 complete [ 4417.764037] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4419.128878] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4420.228273] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 13:10:21 (1772475021) [ 4423.160768] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 4423.160976] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 4423.163262] Lustre: *** cfs_fail_loc=19e, val=0*** [ 4423.758438] Lustre: Failing over lustre-MDT0000 [ 4423.941722] Lustre: server umount lustre-MDT0000 complete [ 4428.595482] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4429.930182] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4430.967465] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 13:10:32 (1772475032) [ 4433.906346] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 4433.906444] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 4441.077913] Lustre: Failing over lustre-MDT0000 [ 4441.293191] Lustre: server umount lustre-MDT0000 complete [ 4442.463373] Lustre: Failing over lustre-MDT0001 [ 4442.573380] Lustre: server umount lustre-MDT0001 complete [ 4445.393850] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4452.832647] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b77050826f0 [ 4454.261902] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4457.125485] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4457.282251] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 4457.282345] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 4458.578306] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4459.296283] Lustre: lustre-MDT0000: Denying connection for new client 56542f6d-0511-464c-9db9-ffc39820be8c (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 4459.302586] Lustre: Skipped 1 previous similar message [ 4462.579358] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 4462.579364] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 4465.272977] Lustre: Failing over lustre-MDT0000 [ 4465.354832] Lustre: server umount lustre-MDT0000 complete [ 4466.522783] Lustre: Failing over lustre-MDT0001 [ 4466.622192] Lustre: server umount lustre-MDT0001 complete [ 4469.312733] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4476.896134] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7705082d56 [ 4478.237881] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4480.847379] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4480.964530] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 4480.965111] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 4482.105135] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4483.055151] Lustre: lustre-MDT0000: Denying connection for new client cf2902f9-8350-4afc-97e7-a826f8f11d21 (at 192.168.201.13@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 4483.059935] Lustre: Skipped 1 previous similar message [ 4486.133666] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 4486.133724] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 4490.554390] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 13:11:31 (1772475091) [ 4493.793579] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4498.402522] Lustre: server umount lustre-MDT0000 complete [ 4499.759987] Lustre: server umount lustre-MDT0001 complete [ 4510.667219] Lustre: server umount lustre-OST0000 complete [ 4521.176289] Lustre: server umount lustre-OST0001 complete [ 4523.143499] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 4525.664852] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4541.087410] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 4546.207303] LustreError: 160549:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.113@tcp: failed processing log, type 4: rc = -110 [ 4573.494127] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4575.166863] Lustre: Failing over lustre-OST0000 [ 4575.211908] Lustre: server umount lustre-OST0000 complete [ 4577.127959] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 4580.189371] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4595.615449] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 4600.735255] LustreError: 162052:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.113@tcp: failed processing log, type 4: rc = -110 [ 4628.283536] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4631.037546] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 13:13:52 (1772475232) [ 4635.493454] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4639.032806] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4639.197849] LustreError: 162076: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. [ 4639.205610] LustreError: 162076:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 16 previous similar messages [ 4639.255621] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 4640.465345] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4643.231824] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4643.347855] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 4644.565349] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4650.155559] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4651.242993] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 4651.254565] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 4651.931044] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4654.794314] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4661.374053] Lustre: *** cfs_fail_loc=193, val=0*** [ 4661.925240] Lustre: Failing over lustre-MDT0000 [ 4662.110502] Lustre: server umount lustre-MDT0000 complete [ 4664.678159] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4664.761361] Lustre: *** cfs_fail_loc=193, val=0*** [ 4664.763011] Lustre: Skipped 1 previous similar message [ 4666.031835] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4669.938927] Lustre: *** cfs_fail_loc=19f, val=0*** [ 4669.941040] Lustre: Skipped 3 previous similar messages [ 4669.942725] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 4669.942728] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 4669.944297] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 4669.944337] Lustre: *** cfs_fail_loc=19f, val=0*** [ 4669.944342] Lustre: Skipped 35 previous similar messages [ 4678.762041] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 13:14:40 (1772475280) [ 4679.703768] Lustre: Failing over lustre-MDT0000 [ 4679.895781] Lustre: server umount lustre-MDT0000 complete [ 4681.222397] Lustre: Failing over lustre-MDT0001 [ 4681.345235] Lustre: server umount lustre-MDT0001 complete [ 4682.224614] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4684.339740] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4691.424333] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbdaa3b7705088c62 [ 4691.540664] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200000400:0x1:0x0]/52 with flags 0x4a: rc = 0 [ 4691.542675] Lustre: 168654:0:(lod_sub_object.c:941:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't open llog [0x200000400:0x1:0x0]: rc = -115 [ 4691.547123] LustreError: 168654:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osd: get update log duration 0, retries 0, failed: rc = -115 [ 4692.735839] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4695.547428] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4696.948917] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4698.531851] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 4701.806379] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 4701.806468] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 4702.821446] LustreError: 169364:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 4702.839666] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 4702.839666] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 4705.520576] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 13:15:06 (1772475306) [ 4707.295621] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4707.297063] Lustre: Skipped 4 previous similar messages [ 4712.526768] Lustre: server umount lustre-MDT0000 complete [ 4713.731641] Lustre: server umount lustre-MDT0001 complete [ 4724.733179] Lustre: server umount lustre-OST0000 complete [ 4735.120837] Lustre: server umount lustre-OST0001 complete [ 4737.129953] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4740.564421] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4741.908759] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4743.647498] Lustre: Failing over lustre-MDT0000 [ 4743.651388] LustreError: 171724:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 4743.654619] LustreError: 171724:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 4743.656935] LustreError: 171724:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 3, retries 0, failed: rc = -5 [ 4743.757447] Lustre: server umount lustre-MDT0000 complete [ 4745.804168] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4749.929827] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4751.281546] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4753.652232] Lustre: DEBUG MARKER: === sanity-scrub: start setup 13:15:54 (1772475354) === [ 4754.307589] LustreError: 173340:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 4754.310499] LustreError: 173340:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 4754.312652] LustreError: 173340:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 4, retries 0, failed: rc = -5 [ 4754.414338] Lustre: server umount lustre-MDT0000 complete [ 4764.323381] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_hostid [ 4766.459837] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4781.690793] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing load_modules_local [ 4785.655561] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4785.743795] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4785.755522] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4785.790689] Lustre: lustre-MDT0000: new disk, initializing [ 4785.814120] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4787.001830] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4791.897672] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4791.931943] Lustre: 178623: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 [ 4791.935375] Lustre: 178623:0:(mgs_llog.c:1348:mgs_modify_param()) Skipped 4 previous similar messages [ 4791.995373] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4793.178990] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4795.419212] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4798.353826] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4798.437115] Lustre: lustre-OST0000: new disk, initializing [ 4798.438239] Lustre: Skipped 1 previous similar message [ 4798.439440] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4798.440788] Lustre: Skipped 2 previous similar messages [ 4799.913452] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4799.916821] Lustre: Skipped 1 previous similar message [ 4799.918717] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4799.934313] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4800.277978] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4805.114890] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4806.948124] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4807.044519] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4811.194723] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4812.252439] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4818.954967] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 13:17:00 (1772475420) === [ 4819.424607] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 4507 sec ========= 13:17:00 (1772475420) [ 4819.944137] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 13:17:01 (1772475421) === [ 4820.916267] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 13:17:02 (1772475422) === [ 4822.496154] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4822.497574] Lustre: Skipped 7 previous similar messages [ 4827.988227] Lustre: server umount lustre-MDT0000 complete [ 4830.434869] LustreError: MGC192.168.201.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4830.439248] LustreError: Skipped 10 previous similar messages [ 4830.530804] Lustre: server umount lustre-MDT0001 complete [ 4843.393083] Lustre: server umount lustre-OST0000 complete [ 4856.396511] Lustre: server umount lustre-OST0001 complete [ 4861.289762] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing unload_modules_local [ 4862.301746] Key type lgssc unregistered [ 4862.430317] LNet: 184909:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4862.432781] LNetError: 184909:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4862.445301] LNet: Removed LNI 192.168.201.113@tcp [ 4862.758141] Key type .llcrypt unregistered [ 4862.758989] Key type ._llcrypt unregistered