[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 492974079 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001014] APIC: Switch to symmetric I/O mode setup [ 0.003108] x2apic enabled [ 0.004008] Switched APIC routing to physical x2apic. [ 0.005012] kvm-guest: setup PV IPIs [ 0.008483] ..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.009027] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010012] pid_max: default: 32768 minimum: 301 [ 0.011132] LSM: Security Framework initializing [ 0.012043] Yama: becoming mindful. [ 0.013035] SELinux: Initializing. [ 0.014056] *** VALIDATE selinux *** [ 0.022750] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027121] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028147] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030105] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031102] *** VALIDATE tmpfs *** [ 0.033165] *** VALIDATE proc *** [ 0.034236] *** VALIDATE cgroup *** [ 0.035008] *** VALIDATE cgroup2 *** [ 0.036264] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038142] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039006] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040029] Spectre V2 : User space: Vulnerable [ 0.041009] Speculative Store Bypass: Vulnerable [ 0.043804] debug: unmapping init [mem 0xffffffffa3059000-0xffffffffa3060fff] [ 0.045238] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046766] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047041] ... version: 2 [ 0.048012] ... bit width: 48 [ 0.049009] ... generic registers: 4 [ 0.050033] ... value mask: 0000ffffffffffff [ 0.051010] ... max period: 00007fffffffffff [ 0.052016] ... fixed-purpose events: 3 [ 0.053012] ... event mask: 000000070000000f [ 0.054320] rcu: Hierarchical SRCU implementation. [ 0.056623] smp: Bringing up secondary CPUs ... [ 0.057608] x86: Booting SMP configuration: [ 0.058022] .... node #0, CPUs: #1 #2 #3 [ 0.065636] smp: Brought up 1 node, 4 CPUs [ 0.067022] smpboot: Max logical packages: 1 [ 0.068015] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.148167] node 0 deferred pages initialised in 78ms [ 0.151457] devtmpfs: initialized [ 0.152214] x86/mm: Memory block size: 128MB [ 0.154704] gcov: version magic: 0x41383552 [ 0.156413] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.160132] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.163353] pinctrl core: initialized pinctrl subsystem [ 0.165185] [ 0.165717] ************************************************************* [ 0.168012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.170015] ** ** [ 0.173013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.176013] ** ** [ 0.179020] ** This means that this kernel is built to expose internal ** [ 0.181015] ** IOMMU data structures, which may compromise security on ** [ 0.185027] ** your system. ** [ 0.188014] ** ** [ 0.191017] ** If you see this message and you are not debugging the ** [ 0.194014] ** kernel, report this immediately to your vendor! ** [ 0.196012] ** ** [ 0.198013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.201012] ************************************************************* [ 0.203657] NET: Registered protocol family 16 [ 0.205446] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.208055] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.211065] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.215033] cpuidle: using governor menu [ 0.216754] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.217427] PCI: Using configuration type 1 for base access [ 0.218137] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.223077] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.225024] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.229075] cryptd: max_cpu_qlen set to 1000 [ 0.234328] ACPI: Added _OSI(Module Device) [ 0.236013] ACPI: Added _OSI(Processor Device) [ 0.238015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.240016] ACPI: Added _OSI(Processor Aggregator Device) [ 0.245526] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.252413] ACPI: Interpreter enabled [ 0.254073] ACPI: PM: (supports S0 S3 S4 S5) [ 0.256013] ACPI: Using IOAPIC for interrupt routing [ 0.258095] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.263624] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.275931] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.278046] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.282023] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.286086] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.290519] acpiphp: Slot [2] registered [ 0.292157] acpiphp: Slot [5] registered [ 0.293116] acpiphp: Slot [6] registered [ 0.295094] acpiphp: Slot [7] registered [ 0.296145] acpiphp: Slot [8] registered [ 0.297086] acpiphp: Slot [9] registered [ 0.298117] acpiphp: Slot [10] registered [ 0.300106] acpiphp: Slot [3] registered [ 0.301080] acpiphp: Slot [4] registered [ 0.302089] acpiphp: Slot [11] registered [ 0.303101] acpiphp: Slot [12] registered [ 0.304082] acpiphp: Slot [13] registered [ 0.306088] acpiphp: Slot [14] registered [ 0.307085] acpiphp: Slot [15] registered [ 0.308086] acpiphp: Slot [16] registered [ 0.309087] acpiphp: Slot [17] registered [ 0.311105] acpiphp: Slot [18] registered [ 0.312102] acpiphp: Slot [19] registered [ 0.313159] acpiphp: Slot [20] registered [ 0.315096] acpiphp: Slot [21] registered [ 0.316086] acpiphp: Slot [22] registered [ 0.317175] acpiphp: Slot [23] registered [ 0.318126] acpiphp: Slot [24] registered [ 0.319000] acpiphp: Slot [25] registered [ 0.319000] acpiphp: Slot [26] registered [ 0.321091] acpiphp: Slot [27] registered [ 0.322091] acpiphp: Slot [28] registered [ 0.323090] acpiphp: Slot [29] registered [ 0.325108] acpiphp: Slot [30] registered [ 0.326101] acpiphp: Slot [31] registered [ 0.327066] PCI host bridge to bus 0000:00 [ 0.329044] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.331018] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.333020] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.335022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.336020] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.338025] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.340158] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.341987] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.345232] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.354693] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.359742] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.364025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.368021] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.371020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.374565] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.375779] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.381072] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.386712] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.393018] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.408000] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.415009] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.422018] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.441015] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.450041] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.488016] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.499014] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.512017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.523015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.541024] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.554840] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.571017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.609018] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.653031] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.667662] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.678017] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.690016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.727018] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.742534] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.756016] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.763017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.781015] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.794186] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.807015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.818015] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.841017] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.853249] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.855359] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.858364] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.861393] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.864231] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.870036] iommu: Default domain type: Passthrough [ 0.872450] SCSI subsystem initialized [ 0.874210] ACPI: bus type USB registered [ 0.875099] usbcore: registered new interface driver usbfs [ 0.878189] usbcore: registered new interface driver hub [ 0.880096] usbcore: registered new device driver usb [ 0.882201] pps_core: LinuxPPS API ver. 1 registered [ 0.884011] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.887103] PTP clock support registered [ 0.890081] EDAC MC: Ver: 3.0.0 [ 0.892156] PCI: Using ACPI for IRQ routing [ 0.894983] NetLabel: Initializing [ 0.896011] NetLabel: domain hash size = 128 [ 0.898009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.900079] NetLabel: unlabeled traffic allowed by default [ 0.902090] vgaarb: loaded [ 0.904125] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.906009] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.911469] clocksource: Switched to clocksource kvm-clock [ 1.029048] VFS: Disk quotas dquot_6.6.0 [ 1.030576] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.032984] *** VALIDATE ramfs *** [ 1.034268] *** VALIDATE hugetlbfs *** [ 1.035586] pnp: PnP ACPI init [ 1.038935] pnp: PnP ACPI: found 6 devices [ 1.059785] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.062608] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.064447] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.066236] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.068404] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.071366] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.073613] NET: Registered protocol family 2 [ 1.075565] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.079584] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.082585] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.087765] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.090642] TCP: Hash tables configured (established 65536 bind 65536) [ 1.093119] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.095954] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.098607] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.101131] NET: Registered protocol family 1 [ 1.105195] RPC: Registered named UNIX socket transport module. [ 1.107128] RPC: Registered udp transport module. [ 1.108494] RPC: Registered tcp transport module. [ 1.109931] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.111980] NET: Registered protocol family 44 [ 1.113276] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.115101] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.116782] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.119015] PCI: CLS 0 bytes, default 64 [ 1.120422] Unpacking initramfs... [ 2.596687] debug: unmapping init [mem 0xffff8eb4fcc54000-0xffff8eb4fffbffff] [ 2.600722] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.603290] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.606630] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.095888] Initialise system trusted keyrings [ 3.097450] Key type blacklist registered [ 3.099443] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.109184] zbud: loaded [ 3.130169] *** VALIDATE nfs *** [ 3.131386] *** VALIDATE nfs4 *** [ 3.132925] pstore: using deflate compression [ 3.136518] Platform Keyring initialized [ 3.249755] NET: Registered protocol family 38 [ 3.251862] Key type asymmetric registered [ 3.254477] Asymmetric key parser 'x509' registered [ 3.256671] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.260229] io scheduler mq-deadline registered [ 3.262116] io scheduler kyber registered [ 3.264148] io scheduler bfq registered [ 3.268208] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.271118] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.273674] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.276387] ACPI: Power Button [PWRF] [ 3.281921] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.289138] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.304693] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.319259] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.341545] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.371016] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.401053] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.406687] Non-volatile memory driver v1.3 [ 3.408993] Linux agpgart interface v0.103 [ 3.446975] virtio_blk virtio1: [vda] 145192 512-byte logical blocks (74.3 MB/70.9 MiB) [ 3.450264] vda: detected capacity change from 0 to 74338304 [ 3.491261] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.494522] vdb: detected capacity change from 0 to 1073741824 [ 3.512375] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.516210] vdc: detected capacity change from 0 to 2621440000 [ 3.529334] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.532609] vdd: detected capacity change from 0 to 2621440000 [ 3.550251] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.553512] vde: detected capacity change from 0 to 4294967296 [ 3.569819] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.576871] vdf: detected capacity change from 0 to 4294967296 [ 3.586388] libphy: Fixed MDIO Bus: probed [ 3.591732] usbcore: registered new interface driver usbserial_generic [ 3.594508] usbserial: USB Serial support registered for generic [ 3.596845] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.601550] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.604207] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.607327] mousedev: PS/2 mouse device common for all mice [ 3.611468] rtc_cmos 00:05: RTC can wake from S4 [ 3.617938] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.618570] rtc_cmos 00:05: registered as rtc0 [ 3.626626] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.626728] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.631682] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.632663] intel_pstate: CPU model not supported [ 3.638572] hid: raw HID events driver (C) Jiri Kosina [ 3.643645] usbcore: registered new interface driver usbhid [ 3.645854] usbhid: USB HID core driver [ 3.647658] drop_monitor: Initializing network drop monitor service [ 3.650459] Initializing XFRM netlink socket [ 3.652665] NET: Registered protocol family 10 [ 3.656076] Segment Routing with IPv6 [ 3.657315] NET: Registered protocol family 17 [ 3.659294] mpls_gso: MPLS GSO support [ 3.674399] RAS: Correctable Errors collector initialized. [ 3.677286] AVX version of gcm_enc/dec engaged. [ 3.679752] AES CTR mode by8 optimization enabled [ 3.762226] sched_clock: Marking stable (3762204797, 0)->(4690151344, -927946547) [ 3.764612] registered taskstats version 1 [ 3.767463] Loading compiled-in X.509 certificates [ 3.769676] zswap: loaded using pool lzo/zbud [ 3.805065] Key type big_key registered [ 3.821759] Key type encrypted registered [ 3.823632] ima: No TPM chip found, activating TPM-bypass! [ 3.825964] ima: Allocated hash algorithm: sha1 [ 3.828513] ima: No architecture policies found [ 3.830597] evm: Initialising EVM extended attributes: [ 3.832733] evm: security.selinux [ 3.834137] evm: security.ima [ 3.835359] evm: security.capability [ 3.836657] evm: HMAC attrs: 0x1 [ 3.838600] rtc_cmos 00:05: setting system clock to 2026-07-04 05:04:51 UTC (1783141491) [ 3.847975] debug: unmapping init [mem 0xffffffffa4003000-0xffffffffa41fffff] [ 3.852091] debug: unmapping init [mem 0xffffffffa2d82000-0xffffffffa3058fff] [ 3.865262] Write protecting the kernel read-only data: 28672k [ 3.868252] debug: unmapping init [mem 0xffffffffa1403000-0xffffffffa15fffff] [ 3.870275] debug: unmapping init [mem 0xffffffffa1d14000-0xffffffffa1dfffff] [ 3.905839] 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.917178] systemd[1]: Detected virtualization kvm. [ 3.919666] systemd[1]: Detected architecture x86-64. [ 3.922188] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.953046] systemd[1]: No hostname configured. [ 3.955062] systemd[1]: Set hostname to . [ 3.958341] random: systemd: uninitialized urandom read (16 bytes read) [ 3.961930] systemd[1]: Initializing machine ID from random generator. [ 4.009720] random: ln: uninitialized urandom read (6 bytes read) [ 4.108659] random: systemd: uninitialized urandom read (16 bytes read) [ 4.114028] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 4.124386] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 4.133903] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... [ OK ] Reached target Timers. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Journal Socket (/dev/log). Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Journal Service... [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.846750] device-mapper: uevent: version 1.0.3 [ 4.850518] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ 5.658528] random: fast init done [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.687586] virtio_net virtio0 ens2: renamed from eth0 Starting dracut initqueue hook... [ 5.760420] scsi host0: ata_piix [ 5.780877] scsi host1: ata_piix [ 5.783465] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.790512] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.818026] dracut-initqueue[581]: RTNETLINK answers: File exists [ 10.341563] random: crng init done [ 10.343089] 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.097867] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Sockets. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.494790] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.764253] SELinux: Disabled at runtime. [ 12.831933] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.846993] systemd[1]: Detected virtualization kvm. [ 12.850016] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.390760] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.395234] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.403888] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.407967] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.411213] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.419427] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.426080] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. Mounting POSIX Message Queue File System... Starting Create list of required st…ce nodes for the current kernel... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. Mounting Huge Pages File System... Starting Remount Root and Kernel File Systems... [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... Starting Apply Kernel Variables... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Listening on Process Core Dump Socket. Activating swap /dev/disk/by-label/SWAP... Mounting Kernel Debug File System... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target P[ 13.628653] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS aths. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Reached target Slices. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 14.036814] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 14.405930] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 14.462921] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 15.245725] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 15.260746] EDAC sbridge: Ver: 1.1.2 [ 16.962885] Key type dns_resolver registered [ 17.271941] NFS: Registering the id_resolver key type [ 17.273561] Key type id_resolver registered [ 17.275142] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started RPC Bind. [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ 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... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg416-server login: [ 50.837881] libcfs: loading out-of-tree module taints kernel. [ 50.916571] Key type ._llcrypt registered [ 50.920544] Key type .llcrypt registered [ 51.107279] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_hostid [ 69.789491] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 70.978152] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 71.003425] alg: No test for adler32 (adler32-zlib) [ 72.828950] Lustre: Lustre: Build Version: 2.17.54_86_gcbe30f7 [ 73.614348] LNet: Added LNI 192.168.204.116@tcp [8/256/0/180] [ 75.335170] Key type lgssc registered [ 77.597301] Lustre: Echo OBD driver; http://www.lustre.org/ [ 80.955115] hrtimer: interrupt took 5097073 ns [ 95.993149] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 137.639890] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 151.318938] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 151.360736] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 152.663830] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 152.730821] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 152.839704] Lustre: lustre-MDT0000: new disk, initializing [ 152.954121] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 153.000497] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 158.002065] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 171.237783] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 171.348006] Lustre: 6502:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 171.377979] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 171.383823] Lustre: Skipped 1 previous similar message [ 171.500148] Lustre: lustre-MDT0001: new disk, initializing [ 171.627617] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 171.667057] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 171.697453] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 176.482615] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 181.487792] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 191.523715] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 191.788741] Lustre: lustre-OST0000: new disk, initializing [ 191.792193] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 191.806201] Lustre: 8440:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 191.865411] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 196.114038] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 196.126221] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 196.182116] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 198.048063] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 211.976481] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 212.168486] Lustre: lustre-OST0001: new disk, initializing [ 212.172698] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 212.177815] Lustre: 9515:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 212.264540] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 219.120612] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 220.210418] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 220.219418] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 220.317729] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 230.775402] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 236.300547] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 242.655480] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing check_logdir /tmp/testlogs/ [ 247.466189] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing yml_node [ 252.078427] Lustre: DEBUG MARKER: Client: 2.17.54.86 [ 254.921490] Lustre: DEBUG MARKER: MDS: 2.17.54.86 [ 257.344559] Lustre: DEBUG MARKER: OSS: 2.17.54.86 [ 259.216888] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Sat Jul 4 01:09:04 EDT 2026 [ 277.832622] Lustre: DEBUG MARKER: excepting tests: [ 289.051390] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 296.932125] 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 [ 296.945231] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 296.958510] Lustre: Skipped 1 previous similar message [ 296.969465] Lustre: Skipped 3 previous similar messages [ 302.056520] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 302.072074] Lustre: Skipped 3 previous similar messages [ 302.685144] Lustre: server umount lustre-MDT0000 complete [ 311.293514] LustreError: 8439:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783141798 with bad export cookie 12196010502843666942 [ 311.299783] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 311.303296] LustreError: 8439:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 311.727520] Lustre: server umount lustre-MDT0001 complete [ 327.519169] Lustre: 3637:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783141799/real 1783141799] req@ffff8eb443889180 x1869759445570432/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783141815 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 327.557187] 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 [ 327.565794] Lustre: Skipped 2 previous similar messages [ 330.852468] Lustre: server umount lustre-OST0000 complete [ 331.743103] Lustre: 3640:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783141803/real 1783141803] req@ffff8eb44384c700 x1869759445570688/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783141819 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 333.727186] Lustre: 3637:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783141805/real 1783141805] req@ffff8eb57c2a8a80 x1869759445570944/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783141821 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 336.865265] Lustre: 3639:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783141808/real 1783141808] req@ffff8eb57c2a8380 x1869759445571328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783141824 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 339.454763] Lustre: server umount lustre-OST0001 complete [ 355.958454] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing unload_modules_local [ 358.991485] Key type lgssc unregistered [ 359.407570] LNet: 14784:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 359.418099] LNetError: 14784:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 359.446240] LNet: Removed LNI 192.168.204.116@tcp [ 360.380166] Key type .llcrypt unregistered [ 360.381968] Key type ._llcrypt unregistered [ 384.837796] Key type ._llcrypt registered [ 384.844570] Key type .llcrypt registered [ 385.008195] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_hostid [ 401.059826] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 401.962199] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 402.272932] alg: No test for adler32 (adler32-zlib) [ 403.342386] Lustre: Lustre: Build Version: 2.17.54_86_gcbe30f7 [ 403.667734] LNet: Added LNI 192.168.204.116@tcp [8/256/0/180] [ 405.415174] Key type lgssc registered [ 406.816441] Lustre: Echo OBD driver; http://www.lustre.org/ [ 458.154914] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 473.547341] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 473.584821] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 475.003729] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 475.064697] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 475.246144] Lustre: lustre-MDT0000: new disk, initializing [ 475.374213] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 475.394048] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 480.858261] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 495.127499] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 495.234295] Lustre: 19242:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 495.265869] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 495.275286] Lustre: Skipped 1 previous similar message [ 495.392432] Lustre: lustre-MDT0001: new disk, initializing [ 495.436097] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 495.480792] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 495.493520] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 500.399475] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 505.684369] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 515.873668] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 516.136856] Lustre: lustre-OST0000: new disk, initializing [ 516.141037] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 516.153363] Lustre: 21182:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 516.235507] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 518.401141] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 518.424353] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 518.503301] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 522.813352] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 537.610483] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 537.755947] Lustre: lustre-OST0001: new disk, initializing [ 537.760476] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 537.768488] Lustre: 22207:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 537.845779] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 543.770395] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 543.791312] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 543.865423] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 544.172466] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 555.352403] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 566.739515] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 574.851585] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 01:14:20 (1783142060) === [ 576.432798] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 01:14:22 (1783142062) [ 595.657813] Lustre: Failing over lustre-MDT0000 [ 595.911220] Lustre: server umount lustre-MDT0000 complete [ 597.983814] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 597.999688] 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 [ 599.415862] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142087 with bad export cookie 1077426973413779555 [ 599.420333] Lustre: Failing over lustre-MDT0001 [ 599.422890] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 599.435230] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 599.779783] Lustre: server umount lustre-MDT0001 complete [ 608.070210] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 610.060208] LustreError: 21174: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. [ 610.064223] 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 [ 610.083137] LustreError: 21174:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 610.097364] Lustre: Skipped 2 previous similar messages [ 610.148090] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 610.181632] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 614.471523] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 615.405521] LustreError: 24243: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. [ 615.427078] LustreError: 24243:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 615.428052] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 616.415326] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142087/real 1783142087] req@ffff8eb44a964e00 x1869759791627136/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142103 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 616.464503] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 619.488990] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142091/real 1783142091] req@ffff8eb442625f80 x1869759791627904/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142107 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 619.522966] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 620.517768] LustreError: 24221: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. [ 620.544502] LustreError: 24221:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 623.134259] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 623.330942] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 623.415771] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 623.449395] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 623.462382] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 624.417107] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142096/real 1783142096] req@ffff8eb44a928380 x1869759791628160/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142112 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 624.464865] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 627.799785] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 628.723024] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 628.736915] Lustre: Skipped 1 previous similar message [ 628.756602] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 628.793453] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 628.855515] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 628.858441] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 641.235709] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 01:15:26 (1783142126) [ 661.895119] Lustre: Failing over lustre-MDT0000 [ 662.287655] Lustre: server umount lustre-MDT0000 complete [ 664.544061] 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 [ 664.545952] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 664.547811] LustreError: 24221: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. [ 664.569616] Lustre: Skipped 3 previous similar messages [ 666.225215] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142153 with bad export cookie 1077426973413795879 [ 666.230156] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 666.231255] Lustre: Failing over lustre-MDT0001 [ 666.243190] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 666.696328] Lustre: server umount lustre-MDT0001 complete [ 675.896772] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 686.047215] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142157/real 1783142157] req@ffff8eb44a964000 x1869759791744256/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142173 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 686.098186] 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 [ 686.111574] Lustre: Skipped 1 previous similar message [ 691.168612] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142162/real 1783142162] req@ffff8eb44a967100 x1869759791744768/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142178 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 691.198557] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 691.234313] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb44a967480 x1869759791746304/t0(0) o250->MGC192.168.204.116@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 [ 691.627314] LustreError: 21175: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. [ 691.659870] LustreError: 21175:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 691.741379] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 691.780861] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 697.212552] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 700.898461] LustreError: 26610: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. [ 700.926864] LustreError: 26610:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 700.950676] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142172/real 1783142172] req@ffff8eb44a966300 x1869759791745664/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142188 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 701.008564] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 705.002744] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 705.016201] Lustre: Skipped 2 previous similar messages [ 706.013373] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 706.223143] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 706.349920] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 706.355927] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 711.122653] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 711.652067] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 711.660846] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 711.680785] Lustre: Skipped 1 previous similar message [ 711.710917] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 711.770353] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 711.771919] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 715.309454] Lustre: *** cfs_fail_loc=193, val=0*** [ 720.495395] Lustre: Failing over lustre-MDT0000 [ 720.865900] Lustre: server umount lustre-MDT0000 complete [ 721.897787] 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 [ 721.902455] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 721.914955] Lustre: Skipped 1 previous similar message [ 721.916728] LustreError: 26610: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. [ 721.916736] LustreError: 26610:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 729.053707] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 729.202932] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 729.488201] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 729.494769] Lustre: Skipped 1 previous similar message [ 729.525022] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 733.854765] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 734.691355] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 734.701338] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 734.715650] Lustre: Skipped 2 previous similar messages [ 734.747973] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 734.791361] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 734.795233] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 743.088744] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 01:17:08 (1783142228) [ 757.382182] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 774.938320] Lustre: 30490:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 794.474694] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 797.377649] Lustre: 31625:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 809.355147] Lustre: *** cfs_fail_loc=198, val=0*** [ 819.006496] Lustre: Failing over lustre-MDT0000 [ 819.243224] Lustre: server umount lustre-MDT0000 complete [ 821.732509] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 821.733362] 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 [ 821.747695] LustreError: 21174: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. [ 821.758437] Lustre: Skipped 6 previous similar messages [ 821.792941] LustreError: 21174:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 822.557440] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142310 with bad export cookie 1077426973413824796 [ 822.557547] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 822.560726] Lustre: Failing over lustre-MDT0001 [ 822.578166] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 822.888495] Lustre: server umount lustre-MDT0001 complete [ 827.371486] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 831.433465] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 839.542765] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 843.231326] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142314/real 1783142314] req@ffff8eb580f5bb80 x1869759791913984/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142330 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 843.238680] 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 [ 843.286419] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 843.331281] Lustre: Skipped 1 previous similar message [ 847.810881] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 847.866969] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 852.136748] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 860.255514] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 860.494356] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 860.637536] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 860.643147] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 861.606586] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 861.626973] Lustre: Skipped 3 previous similar messages [ 861.646172] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 861.676392] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 861.719048] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 861.719243] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 864.803719] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 876.478767] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 01:19:22 (1783142362) [ 897.088303] Lustre: Failing over lustre-MDT0000 [ 897.409338] Lustre: server umount lustre-MDT0000 complete [ 897.504514] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 897.509753] 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 [ 897.521619] LustreError: 33100: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. [ 897.537790] Lustre: Skipped 2 previous similar messages [ 897.550490] LustreError: 33100:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 900.516356] Lustre: Failing over lustre-MDT0001 [ 900.517136] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142388 with bad export cookie 1077426973413852236 [ 900.519414] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 900.549741] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 900.906303] Lustre: server umount lustre-MDT0001 complete [ 904.847164] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 908.437396] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 915.455594] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 915.486678] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 918.944862] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142390/real 1783142390] req@ffff8eb44a589180 x1869759792030208/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142406 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 918.972277] Lustre: 16405:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 926.521562] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 930.389823] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 937.395784] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 937.431143] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 937.657708] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 937.658797] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:233 to 0x280000400:257) [ 938.663080] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 938.672802] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 938.683320] Lustre: Skipped 4 previous similar messages [ 938.724565] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 938.758435] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 938.758667] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 941.106677] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 959.198456] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 972.356223] Lustre: 38916:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 991.058563] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 994.290240] Lustre: 40051:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1013.518413] Lustre: Failing over lustre-MDT0000 [ 1013.830759] Lustre: server umount lustre-MDT0000 complete [ 1015.775978] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1015.781414] LustreError: Skipped 1 previous similar message [ 1015.782326] 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 [ 1015.800302] Lustre: Skipped 5 previous similar messages [ 1016.775528] LustreError: 19233:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142504 with bad export cookie 1077426973413879648 [ 1016.779657] Lustre: Failing over lustre-MDT0001 [ 1016.780313] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1016.790430] LustreError: 19233:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1017.181909] Lustre: server umount lustre-MDT0001 complete [ 1021.389195] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1027.678400] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1037.283927] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142508/real 1783142508] req@ffff8eb5440cd500 x1869759792163328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142524 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1037.291987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1037.305375] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1037.386128] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1041.439561] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb5440cc380 x1869759792165504/t0(0) o250->MGC192.168.204.116@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 [ 1041.713980] LustreError: 21174: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. [ 1041.736366] LustreError: 21174:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 11 previous similar messages [ 1041.793326] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1041.798462] Lustre: Skipped 3 previous similar messages [ 1041.834089] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1045.999287] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1053.865223] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1053.920351] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1054.332077] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1054.332558] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1056.358257] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1056.361118] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1056.375282] Lustre: Skipped 4 previous similar messages [ 1056.395136] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1056.432682] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1056.447262] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 1058.086758] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1078.787316] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 1093.303722] Lustre: 44758:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1111.441528] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1114.951387] Lustre: 45893:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1134.706198] Lustre: Failing over lustre-MDT0000 [ 1134.964972] Lustre: server umount lustre-MDT0000 complete [ 1137.920374] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142625 with bad export cookie 1077426973413906822 [ 1137.928098] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1137.931186] Lustre: Failing over lustre-MDT0001 [ 1137.933277] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1138.252113] Lustre: server umount lustre-MDT0001 complete [ 1142.458908] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1148.875766] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1154.527171] 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 [ 1154.540854] Lustre: Skipped 5 previous similar messages [ 1158.237213] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1158.307938] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1162.787326] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb57ea72680 x1869759792300160/t0(0) o250->MGC192.168.204.116@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 [ 1163.156428] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1165.161474] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1165.169565] Lustre: Skipped 4 previous similar messages [ 1167.156078] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1169.248127] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142640/real 1783142640] req@ffff8eb44a588000 x1869759792299136/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142656 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1169.280717] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 26 previous similar messages [ 1174.840417] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1174.878549] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1175.080396] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1175.087160] LustreError: Skipped 1 previous similar message [ 1175.187419] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:361 to 0x280000400:385) [ 1175.189022] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1178.808687] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1180.647865] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1180.677840] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1180.724286] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 1180.725223] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 1192.117883] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 01:24:37 (1783142677) [ 1202.139939] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 1215.549766] Lustre: 50600:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1233.097570] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1254.520784] Lustre: Failing over lustre-MDT0000 [ 1254.792676] Lustre: server umount lustre-MDT0000 complete [ 1257.618703] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142745 with bad export cookie 1077426973413933996 [ 1257.620289] Lustre: Failing over lustre-MDT0001 [ 1257.621788] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1257.628370] LustreError: 21181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1257.905853] Lustre: server umount lustre-MDT0001 complete [ 1261.972130] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1268.788278] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1274.888272] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1282.745487] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1292.628182] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1292.644768] Lustre: lustre-MDT0000: reset Object Index mappings [ 1303.577115] LustreError: 25271: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. [ 1303.591641] LustreError: 25271:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 20 previous similar messages [ 1303.656166] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1303.662454] Lustre: Skipped 3 previous similar messages [ 1303.691812] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1307.332305] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1314.233223] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1314.252457] Lustre: lustre-MDT0001: reset Object Index mappings [ 1314.537319] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 1314.553802] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1318.140755] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1319.920386] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1319.926429] Lustre: Skipped 4 previous similar messages [ 1319.951521] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1319.999619] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1320.048720] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1320.060731] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 1328.596701] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 01:26:54 (1783142814) [ 1347.623625] Lustre: Failing over lustre-MDT0000 [ 1347.869494] Lustre: server umount lustre-MDT0000 complete [ 1350.797837] Lustre: Failing over lustre-MDT0001 [ 1350.799731] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142838 with bad export cookie 1077426973413961170 [ 1350.800282] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1350.824711] LustreError: 19235:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1351.044178] Lustre: server umount lustre-MDT0001 complete [ 1355.732767] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1363.634214] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1370.078593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1378.055044] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1387.510146] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1387.523694] Lustre: lustre-MDT0000: reset Object Index mappings [ 1395.679555] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb57c1ab480 x1869759792547072/t0(0) o250->MGC192.168.204.116@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 [ 1395.998538] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1399.430951] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1406.249562] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1406.271603] Lustre: lustre-MDT0001: reset Object Index mappings [ 1406.583665] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:490 to 0x280000400:513) [ 1406.583786] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:489 to 0x2c0000400:513) [ 1409.824033] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1411.552121] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1411.583113] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1411.618142] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:521 to 0x2c0000401:545) [ 1411.623635] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 1415.435966] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32032: rc = 0 [ 1416.594374] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 1434.339919] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 01:28:40 (1783142920) [ 1452.921632] Lustre: Failing over lustre-MDT0000 [ 1453.154223] Lustre: server umount lustre-MDT0000 complete [ 1455.584493] 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 [ 1455.600207] Lustre: Skipped 14 previous similar messages [ 1455.946723] LustreError: 19234:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783142943 with bad export cookie 1077426973413988449 [ 1455.949568] Lustre: Failing over lustre-MDT0001 [ 1455.958312] LustreError: 19234:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1456.232410] Lustre: server umount lustre-MDT0001 complete [ 1460.381908] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1468.180671] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1475.128765] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1476.895255] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783142948/real 1783142948] req@ffff8eb56d997480 x1869759792669184/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783142964 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1476.937780] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 1482.468030] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1491.332399] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1491.353655] Lustre: lustre-MDT0000: reset Object Index mappings [ 1500.512571] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xef3ca1fb5c444b0 [ 1503.673784] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1509.358667] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1509.377576] Lustre: lustre-MDT0001: reset Object Index mappings [ 1509.517826] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1509.524301] LustreError: Skipped 3 previous similar messages [ 1509.607301] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1509.608674] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1512.322817] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1515.051624] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1515.052027] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:585 to 0x280000401:609) [ 1517.718082] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32009: rc = 0 [ 1520.940758] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 1630.642867] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 01:31:56 (1783143116) [ 1657.116788] Lustre: Failing over lustre-MDT0000 [ 1657.286836] Lustre: server umount lustre-MDT0000 complete [ 1659.520445] LustreError: 19233:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783143147 with bad export cookie 1077426973414016176 [ 1659.520678] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1659.520683] LustreError: Skipped 1 previous similar message [ 1659.524307] Lustre: Failing over lustre-MDT0001 [ 1659.528397] LustreError: 19233:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1659.730685] Lustre: server umount lustre-MDT0001 complete [ 1663.422725] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1670.154644] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1676.189230] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1682.577378] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1690.473623] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1690.503342] Lustre: lustre-MDT0000: reset Object Index mappings [ 1704.671135] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1704.680451] Lustre: Skipped 1 previous similar message [ 1707.749269] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1713.923734] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1714.142969] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:618 to 0x280000400:641) [ 1714.145537] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:617 to 0x2c0000400:641) [ 1717.678142] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1719.267388] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1719.271084] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1719.274449] Lustre: Skipped 1 previous similar message [ 1719.286371] Lustre: Skipped 15 previous similar messages [ 1719.307231] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1719.313275] Lustre: Skipped 1 previous similar message [ 1719.343071] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 1719.347163] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 1723.373033] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/32039: rc = 0 [ 1726.534312] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32029 with flags 0x52: rc = 0 [ 1798.630158] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 01:34:44 (1783143284) [ 1810.791654] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1810.793414] Lustre: Skipped 1 previous similar message [ 1811.309138] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1811.313825] Lustre: Skipped 57 previous similar messages [ 1812.316992] Lustre: *** cfs_fail_loc=19b, val=0*** [ 1812.321836] Lustre: Skipped 247 previous similar messages [ 1824.435855] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 01:35:10 (1783143310) [ 1827.696568] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 1827.702772] Lustre: Skipped 149 previous similar messages [ 1827.939681] LustreError: 65689:0:(osd_compat.c:670:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 291/742779920 292/1244701050 [ 1836.796235] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 01:35:22 (1783143322) [ 1867.744864] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1867.750519] Lustre: Skipped 3 previous similar messages [ 1870.098429] Lustre: server umount lustre-MDT0000 complete [ 1872.867862] LustreError: 68461: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. [ 1872.869481] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1872.889483] LustreError: 68461:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 37 previous similar messages [ 1872.898187] Lustre: Skipped 1 previous similar message [ 1877.984501] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1877.992454] Lustre: Skipped 1 previous similar message [ 1878.695188] Lustre: server umount lustre-MDT0001 complete [ 1887.319267] Lustre: server umount lustre-OST0000 complete [ 1895.671734] Lustre: server umount lustre-OST0001 complete [ 1899.561173] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_hostid [ 1904.156535] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 1931.632757] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 1938.431056] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1938.617952] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1938.652709] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1938.707118] Lustre: lustre-MDT0000: new disk, initializing [ 1938.787893] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1938.796104] Lustre: Skipped 7 previous similar messages [ 1938.819652] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1941.562708] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1948.632810] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1948.722561] Lustre: 75744:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1948.735498] Lustre: 75744:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 1 previous similar message [ 1948.753969] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1948.757416] Lustre: Skipped 1 previous similar message [ 1948.810108] Lustre: lustre-MDT0001: new disk, initializing [ 1948.872171] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1948.878624] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1951.728383] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1954.981478] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1958.901683] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1959.056475] Lustre: lustre-OST0000: new disk, initializing [ 1959.060430] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1959.064812] Lustre: 77375:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1960.575654] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1960.587276] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1960.649459] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1962.806751] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1969.731118] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1969.807902] Lustre: lustre-OST0001: new disk, initializing [ 1969.811394] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1969.816631] Lustre: 78249:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1971.402575] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1971.412225] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1971.451768] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1973.451339] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1979.972955] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1982.051914] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1995.631711] Lustre: Failing over lustre-MDT0000 [ 1995.836625] Lustre: server umount lustre-MDT0000 complete [ 1997.281251] 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 [ 1997.288315] Lustre: Skipped 19 previous similar messages [ 1998.098432] LustreError: 75738:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783143485 with bad export cookie 1077426973414154412 [ 1998.100062] Lustre: Failing over lustre-MDT0001 [ 1998.100290] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1998.100296] LustreError: Skipped 1 previous similar message [ 1998.107019] LustreError: 75738:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 5 previous similar messages [ 1998.279379] Lustre: server umount lustre-MDT0001 complete [ 2001.077401] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2006.193769] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2010.513727] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2015.799842] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2018.785782] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783143490/real 1783143490] req@ffff8eb443ad4380 x1869759793137664/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783143506 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2018.800971] Lustre: 16407:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 15 previous similar messages [ 2022.010361] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2022.026448] Lustre: lustre-MDT0000: reset Object Index mappings [ 2022.028914] Lustre: Skipped 1 previous similar message [ 2022.880031] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb57e2ed500 x1869759793139456/t0(0) o250->MGC192.168.204.116@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 [ 2023.145443] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2025.529231] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2030.190585] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2030.339865] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2030.346359] LustreError: Skipped 3 previous similar messages [ 2030.412582] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 2030.412663] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 2032.547725] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2035.681921] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2035.695989] Lustre: lustre-MDT0000: Denying connection for new client 641c1056-c412-4b0b-afcb-4d07f183a3d3 (at 192.168.204.16@tcp), waiting for 1 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:11 [ 2035.707989] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2035.741294] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2035.741957] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 2042.834181] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32011: rc = 0 [ 2042.834206] Lustre: *** cfs_fail_loc=190, val=3*** [ 2043.899693] Lustre: *** cfs_fail_loc=190, val=3*** [ 2043.903601] Lustre: Skipped 1 previous similar message [ 2044.924534] Lustre: *** cfs_fail_loc=190, val=3*** [ 2045.988812] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2047.967229] Lustre: *** cfs_fail_loc=190, val=3*** [ 2047.970065] Lustre: Skipped 2 previous similar messages [ 2052.063572] Lustre: *** cfs_fail_loc=191, val=3*** [ 2052.068111] Lustre: Skipped 2 previous similar messages [ 2054.208832] Lustre: Failing over lustre-MDT0000 [ 2054.336183] Lustre: server umount lustre-MDT0000 complete [ 2056.196936] Lustre: Failing over lustre-MDT0001 [ 2056.366926] Lustre: server umount lustre-MDT0001 complete [ 2061.356286] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2065.375599] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb443ad5880 x1869759793172224/t0(0) o250->MGC192.168.204.116@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 [ 2067.845268] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2072.714604] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2072.950471] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 2072.954400] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:97) [ 2075.253456] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2078.215841] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 2078.216239] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2078.479836] Lustre: Failing over lustre-MDT0000 [ 2078.703973] Lustre: server umount lustre-MDT0000 complete [ 2080.781497] Lustre: Failing over lustre-MDT0001 [ 2080.953065] Lustre: server umount lustre-MDT0001 complete [ 2086.365304] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2086.443032] Lustre: *** cfs_fail_loc=190, val=3*** [ 2090.976055] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb547301c00 x1869759793195008/t0(0) o250->MGC192.168.204.116@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 [ 2093.507940] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2098.111765] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2098.306437] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:129) [ 2098.306779] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 2100.383372] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2103.818065] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:129) [ 2103.818065] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2104.223115] Lustre: *** cfs_fail_loc=192, val=3*** [ 2104.225183] Lustre: Skipped 7 previous similar messages [ 2107.464935] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/117: rc = 0 [ 2107.465201] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2112.761764] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 01:39:59 (1783143599) [ 2129.277060] Lustre: Failing over lustre-MDT0000 [ 2129.376611] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2129.381785] Lustre: Skipped 3 previous similar messages [ 2129.476154] Lustre: server umount lustre-MDT0000 complete [ 2131.542565] Lustre: Failing over lustre-MDT0001 [ 2131.765989] Lustre: server umount lustre-MDT0001 complete [ 2134.574325] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2139.614650] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2143.513740] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2148.530251] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2154.588907] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2154.604093] Lustre: lustre-MDT0000: reset Object Index mappings [ 2154.606245] Lustre: Skipped 1 previous similar message [ 2156.703663] LustreError: 90467:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 2156.710735] LustreError: 90467:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8eb5504bdc00 x1869759793300224/t0(0) o250->MGC192.168.204.116@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1783143644 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2156.722227] LustreError: 90467:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 2157.024388] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb5437a2680 x1869759793301760/t0(0) o250->MGC192.168.204.116@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 [ 2159.332300] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2163.817881] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2164.055964] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 2164.056277] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 2166.135377] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2168.124888] Lustre: lustre-MDT0000: Denying connection for new client 58540e44-7365-4462-bafe-b2154067b359 (at 192.168.204.16@tcp), waiting for 1 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:06 [ 2169.335872] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 2169.335883] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 2175.566910] Lustre: *** cfs_fail_loc=190, val=2*** [ 2175.567660] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32036: rc = 0 [ 2175.568896] Lustre: Skipped 1 previous similar message [ 2178.737900] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32024 with flags 0x52: rc = 0 [ 2199.073521] Lustre: Failing over lustre-MDT0000 [ 2199.200548] Lustre: server umount lustre-MDT0000 complete [ 2201.158623] Lustre: Failing over lustre-MDT0001 [ 2201.295387] Lustre: server umount lustre-MDT0001 complete [ 2206.378420] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2211.296050] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb565306300 x1869759793340544/t0(0) o250->MGC192.168.204.116@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 [ 2213.765566] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2218.588798] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2218.845918] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 2218.856199] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 2220.943141] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:225) [ 2220.949053] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 2221.125745] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2232.233556] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 01:41:58 (1783143718) [ 2239.741830] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 2248.976710] Lustre: 96421:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2261.956719] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2288.039616] Lustre: Failing over lustre-MDT0000 [ 2290.186361] Lustre: server umount lustre-MDT0000 complete [ 2292.044355] Lustre: Failing over lustre-MDT0001 [ 2292.196938] Lustre: server umount lustre-MDT0001 complete [ 2294.928887] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2299.896932] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2304.359716] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2309.646114] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2315.751916] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2315.770259] Lustre: lustre-MDT0000: reset Object Index mappings [ 2315.775228] Lustre: Skipped 1 previous similar message [ 2316.767390] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb5504c0000 x1869759793471360/t0(0) o250->MGC192.168.204.116@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 [ 2319.012457] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2319.015898] Lustre: Skipped 29 previous similar messages [ 2319.208444] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2323.922960] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2324.124735] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 2324.129436] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 2326.067399] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2328.151595] Lustre: lustre-MDT0000: Denying connection for new client dcec70e4-4a5b-40bb-a3e3-1a1e7e3a99a4 (at 192.168.204.16@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2329.595878] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 2329.597563] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 2335.414845] Lustre: *** cfs_fail_loc=190, val=3*** [ 2335.414899] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32027: rc = 0 [ 2335.418309] Lustre: Skipped 30 previous similar messages [ 2335.426855] Lustre: Skipped 2 previous similar messages [ 2338.528226] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2351.749159] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 01:43:58 (1783143838) [ 2374.439596] Lustre: Failing over lustre-MDT0000 [ 2374.602986] Lustre: server umount lustre-MDT0000 complete [ 2376.244117] Lustre: Failing over lustre-MDT0001 [ 2376.385219] Lustre: server umount lustre-MDT0001 complete [ 2379.155392] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2383.798581] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2388.130544] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2392.699053] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2398.404748] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2400.543662] LustreError: 105327:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 2400.549421] LustreError: 105327:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8eb44ab68380 x1869759793594752/t0(0) o250->MGC192.168.204.116@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1783143888 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2400.558186] LustreError: 105327:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 2401.247513] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb57e2fc700 x1869759793595904/t0(0) o250->MGC192.168.204.116@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 [ 2403.443139] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2408.024546] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2408.247775] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 2408.247829] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:329 to 0x280000400:353) [ 2410.561612] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2413.577582] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 2413.577591] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 2432.484657] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 01:45:18 (1783143918) [ 2439.903288] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 2449.007910] Lustre: 109074:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2449.014472] Lustre: 109074:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 1 previous similar message [ 2459.845155] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2524.119654] Lustre: Failing over lustre-MDT0000 [ 2524.435660] Lustre: server umount lustre-MDT0000 complete [ 2526.177114] LustreError: 77370: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. [ 2526.191270] LustreError: 77370:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 50 previous similar messages [ 2526.306675] LustreError: 78248:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783144013 with bad export cookie 1077426973414360401 [ 2526.310744] Lustre: Failing over lustre-MDT0001 [ 2526.310909] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2526.310914] LustreError: Skipped 6 previous similar messages [ 2526.313900] LustreError: 78248:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 14 previous similar messages [ 2526.613879] Lustre: server umount lustre-MDT0001 complete [ 2529.290209] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2535.397229] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2541.664440] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2547.749846] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2554.665632] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2570.719767] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb55e41e680 x1869759793760384/t0(0) o250->MGC192.168.204.116@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 [ 2570.930831] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2570.934216] Lustre: Skipped 17 previous similar messages [ 2570.951071] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2570.956403] Lustre: Skipped 6 previous similar messages [ 2572.942337] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2577.589587] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2577.603724] Lustre: lustre-MDT0001: reset Object Index mappings [ 2577.606736] Lustre: Skipped 4 previous similar messages [ 2577.847159] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:393 to 0x2c0000400:417) [ 2577.847529] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 2580.054424] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2583.009321] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2583.018784] Lustre: Skipped 6 previous similar messages [ 2583.025916] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2583.034028] Lustre: Skipped 6 previous similar messages [ 2583.054095] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 2583.061192] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 2625.157530] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 01:48:31 (1783144111) [ 2631.797563] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 2640.229313] Lustre: 116970:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2640.235068] Lustre: 116970:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 1 previous similar message [ 2651.255063] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2762.185054] Lustre: Failing over lustre-MDT0000 [ 2762.207855] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2762.213927] LustreError: Skipped 12 previous similar messages [ 2762.218306] 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 [ 2762.225842] Lustre: Skipped 38 previous similar messages [ 2762.227894] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2764.356921] Lustre: server umount lustre-MDT0000 complete [ 2766.034056] Lustre: Failing over lustre-MDT0001 [ 2766.205814] Lustre: server umount lustre-MDT0001 complete [ 2769.057276] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2773.983934] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2778.000342] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2782.720123] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2784.735300] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783144256/real 1783144256] req@ffff8eb443b29500 x1869759793940096/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783144272 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2784.751468] Lustre: 16406:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 95 previous similar messages [ 2788.593622] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2790.687118] LustreError: 120690:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 2790.693258] LustreError: 120690:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8eb443b2b480 x1869759793940736/t0(0) o250->MGC192.168.204.116@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1783144278 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2790.707277] LustreError: 120690:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 2790.879460] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb44921ed80 x1869759793942272/t0(0) o250->MGC192.168.204.116@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 [ 2793.394828] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2798.221973] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2798.448090] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 2798.449222] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:481) [ 2800.809444] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2803.072340] Lustre: lustre-MDT0000: Denying connection for new client d6f4ac9f-62b7-487a-b05f-8383f7a6f451 (at 192.168.204.16@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2803.609406] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 2803.609417] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 2810.541582] Lustre: *** cfs_fail_loc=190, val=1*** [ 2810.542130] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32010: rc = 0 [ 2810.543512] Lustre: Skipped 28 previous similar messages [ 2812.641738] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32003 with flags 0x52: rc = 0 [ 2816.328838] Lustre: Failing over lustre-MDT0000 [ 2816.463551] Lustre: server umount lustre-MDT0000 complete [ 2818.360948] Lustre: Failing over lustre-MDT0001 [ 2818.497937] Lustre: server umount lustre-MDT0001 complete [ 2823.033859] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2828.768934] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xef3ca1fb5d76bb2 [ 2831.024818] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2835.727719] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2835.925962] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 2835.930274] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:513) [ 2838.013173] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2840.911131] Lustre: Failing over lustre-MDT0000 [ 2840.914752] LustreError: 122945:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 2840.920680] LustreError: 122945:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 2840.927151] LustreError: 122945:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 12, retries 0, failed: rc = -5 [ 2840.934783] Lustre: 122946:0:(ldlm_lib.c:2390:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2840.936986] LustreError: 124206:0:(ldlm_lib.c:2990:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2840.944309] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 2840.964901] LustreError: 122946:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8eb44a5f3480 x1869759793985408/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 [ 2840.976599] LustreError: 122946:0:(lod_dev.c:351:lod_sub_recreate_llog()) lustre-MDT0000-mdtlov: can't access update_log: rc = -5 [ 2841.055600] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2841.162370] Lustre: server umount lustre-MDT0000 complete [ 2843.338697] Lustre: Failing over lustre-MDT0001 [ 2843.342125] LustreError: 123664:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200000009:0x0:0x0]: rc = -5 [ 2843.348415] LustreError: 123664:0:(osp_object.c:618:osp_attr_get()) Skipped 1 previous similar message [ 2843.351680] LustreError: 123664:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0001-mdtlov: can't get id from catalogs: rc = -5 [ 2843.360354] LustreError: 123664:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 8, retries 0, failed: rc = -5 [ 2843.519268] Lustre: server umount lustre-MDT0001 complete [ 2847.800038] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2854.305080] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xef3ca1fb5d7704a [ 2856.521931] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2860.921696] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2861.108104] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:545) [ 2861.109724] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 2863.255164] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2866.178702] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:513) [ 2866.178711] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:513) [ 2871.819234] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 01:52:38 (1783144358) [ 2878.309929] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 2886.834820] Lustre: 128012:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2886.839921] Lustre: 128012:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 1 previous similar message [ 2899.226632] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2913.327885] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 01:53:19 (1783144399) [ 2915.713590] Lustre: *** cfs_fail_loc=195, val=0*** [ 2917.237749] Lustre: Failing over lustre-OST0000 [ 2917.293494] Lustre: server umount lustre-OST0000 complete [ 2921.633952] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2922.795091] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2922.801700] Lustre: Skipped 30 previous similar messages [ 2924.430967] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3118.360703] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 01:56:44 (1783144604) [ 3120.422594] Lustre: *** cfs_fail_loc=196, val=0*** [ 3120.424631] Lustre: Skipped 63 previous similar messages [ 3122.470811] Lustre: Failing over lustre-OST0000 [ 3122.530180] Lustre: server umount lustre-OST0000 complete [ 3126.300388] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3128.998647] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3320.540455] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 02:00:07 (1783144807) [ 3322.814832] Lustre: *** cfs_fail_loc=196, val=0*** [ 3322.817220] Lustre: Skipped 63 previous similar messages [ 3324.860634] Lustre: *** cfs_fail_loc=196, val=0*** [ 3324.862894] Lustre: Skipped 447 previous similar messages [ 3329.106879] Lustre: Failing over lustre-OST0000 [ 3329.166193] Lustre: server umount lustre-OST0000 complete [ 3331.552717] LustreError: 97631: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. [ 3331.559589] LustreError: 97631:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 26 previous similar messages [ 3333.320028] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3333.428676] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3333.435627] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3333.438159] Lustre: Skipped 7 previous similar messages [ 3335.073381] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3335.076923] Lustre: Skipped 4 previous similar messages [ 3335.082842] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3335.086023] Lustre: Skipped 4 previous similar messages [ 3335.836058] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3342.303863] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3342.307448] Lustre: Skipped 3 previous similar messages [ 3345.773309] Lustre: server umount lustre-MDT0000 complete [ 3347.146916] LustreError: 129874:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783144834 with bad export cookie 1077426973415272522 [ 3347.148045] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3347.152111] LustreError: 129874:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 9 previous similar messages [ 3347.156064] LustreError: Skipped 3 previous similar messages [ 3347.256681] Lustre: server umount lustre-MDT0001 complete [ 3359.180817] Lustre: server umount lustre-OST0000 complete [ 3370.857256] Lustre: server umount lustre-OST0001 complete [ 3374.984228] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 02:01:01 (1783144861) [ 3380.527027] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_hostid [ 3383.323553] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3400.044206] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3404.239319] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3404.339516] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3404.354695] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3404.393513] Lustre: lustre-MDT0000: new disk, initializing [ 3404.430900] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3404.434567] Lustre: Skipped 9 previous similar messages [ 3404.441666] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3406.182648] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3410.995519] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3411.033617] Lustre: 139288:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3411.040687] Lustre: 139288:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 1 previous similar message [ 3411.053813] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3411.056408] Lustre: Skipped 1 previous similar message [ 3411.093388] Lustre: lustre-MDT0001: new disk, initializing [ 3411.126226] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3411.130027] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3412.763297] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3415.243132] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3417.663546] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3417.761582] Lustre: lustre-OST0000: new disk, initializing [ 3417.763765] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3417.766739] Lustre: 140921:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3419.054420] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3419.059053] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3419.089716] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3419.958789] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3424.726659] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3424.780124] Lustre: lustre-OST0001: new disk, initializing [ 3424.782700] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3424.787040] Lustre: 141794:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3426.605097] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3426.609247] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3426.634297] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3427.134043] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3432.234698] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3433.597506] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3441.180167] Lustre: Failing over lustre-MDT0000 [ 3441.431159] Lustre: server umount lustre-MDT0000 complete [ 3442.144901] 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 [ 3442.145406] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3442.149890] Lustre: Skipped 24 previous similar messages [ 3442.157058] LustreError: Skipped 8 previous similar messages [ 3442.736686] Lustre: Failing over lustre-MDT0001 [ 3442.856633] Lustre: server umount lustre-MDT0001 complete [ 3444.893256] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3448.413328] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3451.447471] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3455.202071] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3459.242705] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3459.249036] Lustre: lustre-MDT0000: reset Object Index mappings [ 3459.250305] Lustre: Skipped 2 previous similar messages [ 3462.431148] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1783144934/real 1783144934] req@ffff8eb44c3d9c00 x1869759794446720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1783144950 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3462.441350] Lustre: 16408:0:(client.c:2489:ptlrpc_expire_one_request()) Skipped 31 previous similar messages [ 3467.551376] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb44c3d8a80 x1869759794448384/t0(0) o250->MGC192.168.204.116@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 [ 3467.563956] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 3469.126778] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3472.338617] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3472.527462] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 3472.528590] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 3473.602711] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 3473.603314] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 3474.328832] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3492.854330] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 02:02:59 (1783144979) [ 3498.112357] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3514.658540] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3528.746718] Lustre: Failing over lustre-MDT0000 [ 3528.753733] Lustre: *** cfs_fail_loc=199, val=0*** [ 3528.755659] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 3528.759817] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 3528.765442] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 3528.771446] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 3528.777070] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 3528.782206] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 3528.787635] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 3528.793407] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 3528.797992] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 3528.801950] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 3528.805881] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 3528.810100] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 3528.814936] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 3528.819282] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 3528.825020] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 3528.829589] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 3528.834889] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 3528.841530] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 3528.844924] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 3528.851175] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 3528.856860] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 3528.864649] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 3528.872851] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 3528.879143] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 3528.886633] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 3528.892979] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 3528.898348] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 3528.903585] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 3528.909744] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 3528.914647] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 3528.921938] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 3528.925805] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 3528.930266] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 3528.934178] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 3528.942906] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 3528.949285] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 3528.962510] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 3528.970253] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 3528.977598] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 3528.985889] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 3528.991248] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 3528.995359] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 3529.001441] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 3529.008324] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 3529.016128] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 3529.022212] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 3529.029455] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 3529.034230] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 3529.038978] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 3529.045728] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 3529.051542] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 3529.057692] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 3529.064765] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 3529.069241] Lustre: 151470:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 3529.175951] Lustre: server umount lustre-MDT0000 complete [ 3530.626032] Lustre: Failing over lustre-MDT0001 [ 3530.631362] Lustre: *** cfs_fail_loc=199, val=0*** [ 3530.633136] Lustre: Skipped 53 previous similar messages [ 3530.635269] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 3530.640387] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 3530.645539] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 3530.649616] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 3530.655577] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 3530.660205] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 3530.667840] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 3530.672210] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 3530.676971] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 3530.683150] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 3530.687490] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 3530.690804] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 3530.695666] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 3530.700401] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 3530.705397] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 3530.711770] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 3530.717876] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 3530.723752] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 3530.729602] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 3530.736304] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 3530.741568] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 3530.747829] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 3530.754875] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 3530.760646] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 3530.764750] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 3530.768794] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 3530.773551] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 3530.778197] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 3530.782391] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 3530.786176] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 3530.791649] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 3530.795751] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 3530.801483] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 3530.805492] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 3530.810393] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 3530.814287] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 3530.818904] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 3530.825430] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 3530.829661] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 3530.833655] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 3530.838688] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 3530.844189] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 3530.848341] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 3530.853123] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 3530.857680] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 3530.863996] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 3530.869499] Lustre: 151673:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 3530.981916] Lustre: server umount lustre-MDT0001 complete [ 3534.608251] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3534.674212] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 3534.681634] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 3534.687934] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 3534.698088] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 3534.703955] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 3534.712873] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 3534.717715] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 3534.722775] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 3534.729877] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 3534.735600] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 3534.742515] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 3534.749058] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 3534.753161] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 3534.760625] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 3534.766445] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 3534.771284] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 3534.777279] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 3534.782842] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 3534.788776] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 3534.798498] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 3534.807791] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 3534.814529] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 3534.819795] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 3534.826112] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 3534.831090] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 3534.836461] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 3534.842417] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 3534.847899] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 3534.856347] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 3534.862528] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 3534.868615] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 3534.874428] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 3534.880916] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 3534.886685] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 3534.894406] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 3534.900463] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 3534.906418] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 3534.912140] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 3534.917487] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 3534.923896] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 3534.930189] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 3534.936285] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 3534.942146] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 3534.948780] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 3534.954735] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 3534.961988] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 3534.968435] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 3534.974830] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 3534.980464] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 3534.986502] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 3534.993608] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 3535.000701] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 3535.007848] Lustre: 152170:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 3540.960152] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xef3ca1fb5d9f27c [ 3540.963221] Lustre: MGC192.168.204.116@tcp: Connection restored to 0@lo (at 0@lo) [ 3540.966598] Lustre: Skipped 10 previous similar messages [ 3542.610844] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3545.553036] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3545.582543] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 3545.587841] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 3545.591890] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 3545.596547] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 3545.601615] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 3545.606118] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 3545.610280] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 3545.613977] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 3545.617579] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 3545.621990] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 3545.626731] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 3545.630271] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 3545.633587] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 3545.636821] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 3545.640702] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 3545.646299] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 3545.652576] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 3545.657493] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 3545.661878] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 3545.667362] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 3545.675972] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 3545.681727] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 3545.686316] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 3545.691934] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 3545.697556] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 3545.702776] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 3545.707392] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 3545.711969] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 3545.716528] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 3545.720623] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 3545.727269] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 3545.731979] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 3545.735967] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 3545.740645] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 3545.746736] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 3545.753509] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 3545.759328] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 3545.764697] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 3545.769411] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 3545.776114] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 3545.781384] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 3545.786804] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 3545.792405] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 3545.798111] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 3545.802778] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 3545.808282] Lustre: 152915:0:(osd_scrub.c:1855:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 3545.906349] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 3545.906381] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 3547.255478] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3548.036216] Lustre: lustre-MDT0000: Denying connection for new client e7e41855-def7-48b7-a4ea-55bbe7226111 (at 192.168.204.16@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 3551.225396] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 3551.225513] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 3556.496328] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 02:04:03 (1783145043) [ 3556.857755] Lustre: *** cfs_fail_loc=19d, val=0*** [ 3556.859693] Lustre: Skipped 123 previous similar messages [ 3557.589206] Lustre: Failing over lustre-MDT0000 [ 3557.733646] Lustre: server umount lustre-MDT0000 complete [ 3563.268991] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3564.998424] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3566.351083] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 02:04:12 (1783145052) [ 3568.631141] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 3568.631219] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 3568.634751] Lustre: *** cfs_fail_loc=19e, val=0*** [ 3569.293913] Lustre: Failing over lustre-MDT0000 [ 3569.463845] Lustre: server umount lustre-MDT0000 complete [ 3574.759579] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3576.344520] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3577.583102] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 02:04:24 (1783145064) [ 3579.897605] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:193) [ 3579.897964] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:193) [ 3588.037089] Lustre: Failing over lustre-MDT0000 [ 3588.257326] Lustre: server umount lustre-MDT0000 complete [ 3589.547808] Lustre: Failing over lustre-MDT0001 [ 3589.664043] Lustre: server umount lustre-MDT0001 complete [ 3592.495497] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3601.514991] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3604.588062] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3604.739826] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 3604.742106] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 3606.332089] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3607.202743] Lustre: lustre-MDT0000: Denying connection for new client 0f72ccd9-49c4-4c81-96d5-60dbe1c15876 (at 192.168.204.16@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 3610.104069] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 3610.104075] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 3613.412892] Lustre: Failing over lustre-MDT0000 [ 3613.512951] Lustre: server umount lustre-MDT0000 complete [ 3614.910892] Lustre: Failing over lustre-MDT0001 [ 3615.019089] Lustre: server umount lustre-MDT0001 complete [ 3618.120366] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3624.416994] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xef3ca1fb5da6eed [ 3626.134497] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3629.486163] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3629.628132] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 3629.628132] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 3631.111340] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3632.227457] Lustre: lustre-MDT0000: Denying connection for new client 19ee3be0-8ef9-4294-897e-daada0b1d232 (at 192.168.204.16@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 3634.679922] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:289) [ 3634.680686] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:289) [ 3640.240675] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 02:05:26 (1783145126) [ 3644.896409] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3644.900165] Lustre: Skipped 7 previous similar messages [ 3649.375346] Lustre: server umount lustre-MDT0000 complete [ 3650.919917] Lustre: server umount lustre-MDT0001 complete [ 3663.373622] Lustre: server umount lustre-OST0000 complete [ 3675.124052] Lustre: server umount lustre-OST0001 complete [ 3677.899113] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 3681.479054] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3696.927756] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 3702.047326] LustreError: 161644:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.116@tcp: failed processing log, type 4: rc = -110 [ 3729.936085] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3732.160653] Lustre: Failing over lustre-OST0000 [ 3732.213885] Lustre: server umount lustre-OST0000 complete [ 3734.735694] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 3738.979400] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3754.463546] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 3759.583306] LustreError: 163168:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.116@tcp: failed processing log, type 4: rc = -110 [ 3787.384855] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3790.524206] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 02:07:57 (1783145277) [ 3795.436438] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3799.031534] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3799.226669] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 3800.698655] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3804.076322] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3804.213436] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:257) [ 3805.896355] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3807.220844] Lustre: 166077:0:(mgs_llog.c:1447:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3807.226056] Lustre: 166077:0:(mgs_llog.c:1447:mgs_modify_param()) Skipped 2 previous similar messages [ 3813.589762] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3816.096335] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3818.980252] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:321) [ 3818.993727] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 3819.677638] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3822.246891] Lustre: *** cfs_fail_loc=193, val=0*** [ 3822.995424] Lustre: Failing over lustre-MDT0000 [ 3823.111532] Lustre: server umount lustre-MDT0000 complete [ 3826.318519] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3826.427853] Lustre: *** cfs_fail_loc=193, val=0*** [ 3826.429393] Lustre: Skipped 1 previous similar message [ 3828.011431] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3831.800505] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:353) [ 3831.800534] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 3831.817130] Lustre: *** cfs_fail_loc=19f, val=0*** [ 3831.818689] Lustre: Skipped 4 previous similar messages [ 3831.821356] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 3831.821357] Lustre: *** cfs_fail_loc=19f, val=0*** [ 3831.826853] Lustre: Skipped 36 previous similar messages [ 3841.048827] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 02:08:47 (1783145327) [ 3842.009251] Lustre: Failing over lustre-MDT0000 [ 3842.016158] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3842.018375] Lustre: Skipped 3 previous similar messages [ 3842.200865] Lustre: server umount lustre-MDT0000 complete [ 3843.533374] Lustre: Failing over lustre-MDT0001 [ 3843.645489] Lustre: server umount lustre-MDT0001 complete [ 3844.632559] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3847.022447] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3854.303367] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8eb5775dca80 x1869759794870272/t0(0) o250->MGC192.168.204.116@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 [ 3854.309845] LustreError: 16404:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 6 previous similar messages [ 3855.807598] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3858.602825] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3860.047786] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3861.767776] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 3862.635401] LustreError: 170569:0:(update_trans.c:1070:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 3862.645648] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:385) [ 3862.645669] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 3862.660264] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:289) [ 3862.660284] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 3869.125672] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 02:09:15 (1783145355) [ 3872.224675] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3872.227143] Lustre: Skipped 3 previous similar messages [ 3876.311547] Lustre: server umount lustre-MDT0000 complete [ 3877.631170] Lustre: server umount lustre-MDT0001 complete [ 3888.647367] Lustre: server umount lustre-OST0000 complete [ 3900.247137] Lustre: server umount lustre-OST0001 complete [ 3902.895106] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3907.189023] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3908.971821] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3911.000774] Lustre: Failing over lustre-MDT0000 [ 3911.003862] LustreError: 172966:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 3911.008105] LustreError: 172966:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 3911.012985] LustreError: 172966:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 3, retries 0, failed: rc = -5 [ 3911.115579] Lustre: server umount lustre-MDT0000 complete [ 3913.475684] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3918.409939] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3920.055350] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3923.092621] Lustre: DEBUG MARKER: === sanity-scrub: start setup 02:10:09 (1783145409) === [ 3923.922643] LustreError: 174598:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 3923.926899] LustreError: 174598:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 3923.931275] LustreError: 174598:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 5, retries 0, failed: rc = -5 [ 3924.055799] Lustre: server umount lustre-MDT0000 complete [ 3936.404339] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_hostid [ 3939.264812] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3957.195764] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing load_modules_local [ 3961.713556] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3961.805522] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3961.816121] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3961.850941] Lustre: lustre-MDT0000: new disk, initializing [ 3961.882171] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3963.366030] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3968.946232] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3969.066478] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3970.638226] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3973.060746] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3976.483948] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3976.563601] Lustre: lustre-OST0000: new disk, initializing [ 3976.566457] Lustre: Skipped 1 previous similar message [ 3976.569259] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3976.572984] Lustre: Skipped 2 previous similar messages [ 3976.576284] Lustre: 181885:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3976.789307] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3976.791846] Lustre: Skipped 1 previous similar message [ 3976.794165] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3976.809499] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3978.580924] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3983.709431] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3983.759980] Lustre: 182908:0:(osd_compat.c:1271:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3985.196498] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3985.224557] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3985.701608] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3990.096123] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3991.220872] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3993.083720] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 02:11:19 (1783145479) === [ 3993.670629] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 3734 sec ========= 02:11:20 (1783145480) [ 3994.276362] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 02:11:20 (1783145480) === [ 3995.475221] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 02:11:21 (1783145481) === [ 3999.711925] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4002.646152] Lustre: server umount lustre-MDT0000 complete [ 4005.744602] LustreError: 183673:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1783145493 with bad export cookie 1077426973415495773 [ 4005.746258] LustreError: MGC192.168.204.116@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4005.748960] LustreError: 183673:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 12 previous similar messages [ 4005.753017] LustreError: Skipped 10 previous similar messages [ 4005.858482] Lustre: server umount lustre-MDT0001 complete [ 4019.200549] Lustre: server umount lustre-OST0000 complete [ 4032.402373] Lustre: server umount lustre-OST0001 complete [ 4038.086282] Lustre: DEBUG MARKER: oleg416-server.virtnet: executing unload_modules_local [ 4039.191619] Key type lgssc unregistered [ 4039.334323] LNet: 186316:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4039.337388] LNetError: 186316:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4039.349900] LNet: Removed LNI 192.168.204.116@tcp [ 4039.692127] Key type .llcrypt unregistered [ 4039.693630] Key type ._llcrypt unregistered