[ 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 505735160 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: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002331] x2apic enabled [ 0.003008] Switched APIC routing to physical x2apic. [ 0.004013] kvm-guest: setup PV IPIs [ 0.007000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007022] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008010] pid_max: default: 32768 minimum: 301 [ 0.009129] LSM: Security Framework initializing [ 0.011017] Yama: becoming mindful. [ 0.011873] SELinux: Initializing. [ 0.012057] *** VALIDATE selinux *** [ 0.020671] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024579] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025162] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026104] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027108] *** VALIDATE tmpfs *** [ 0.029161] *** VALIDATE proc *** [ 0.030222] *** VALIDATE cgroup *** [ 0.031010] *** VALIDATE cgroup2 *** [ 0.032260] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.033155] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.034007] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.035030] Spectre V2 : User space: Vulnerable [ 0.036010] Speculative Store Bypass: Vulnerable [ 0.039497] debug: unmapping init [mem 0xffffffff83e59000-0xffffffff83e60fff] [ 0.041861] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042651] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043023] ... version: 2 [ 0.044010] ... bit width: 48 [ 0.045011] ... generic registers: 4 [ 0.046010] ... value mask: 0000ffffffffffff [ 0.047012] ... max period: 00007fffffffffff [ 0.048013] ... fixed-purpose events: 3 [ 0.049017] ... event mask: 000000070000000f [ 0.050264] rcu: Hierarchical SRCU implementation. [ 0.052473] smp: Bringing up secondary CPUs ... [ 0.053586] x86: Booting SMP configuration: [ 0.054025] .... node #0, CPUs: #1 #2 #3 [ 0.059024] smp: Brought up 1 node, 4 CPUs [ 0.061013] smpboot: Max logical packages: 1 [ 0.062014] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.230000] node 0 deferred pages initialised in 165ms [ 0.235098] devtmpfs: initialized [ 0.236415] x86/mm: Memory block size: 128MB [ 0.240198] gcov: version magic: 0x41383552 [ 0.243436] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.244101] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.245451] pinctrl core: initialized pinctrl subsystem [ 0.246598] [ 0.247000] ************************************************************* [ 0.249031] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.252022] ** ** [ 0.255026] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.257020] ** ** [ 0.260022] ** This means that this kernel is built to expose internal ** [ 0.263019] ** IOMMU data structures, which may compromise security on ** [ 0.265019] ** your system. ** [ 0.268023] ** ** [ 0.271018] ** If you see this message and you are not debugging the ** [ 0.273019] ** kernel, report this immediately to your vendor! ** [ 0.276036] ** ** [ 0.279021] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.282023] ************************************************************* [ 0.285304] NET: Registered protocol family 16 [ 0.287569] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.290093] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.294102] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.298092] cpuidle: using governor menu [ 0.300161] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.303733] PCI: Using configuration type 1 for base access [ 0.306137] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.315158] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.317068] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.321088] cryptd: max_cpu_qlen set to 1000 [ 0.324302] ACPI: Added _OSI(Module Device) [ 0.326022] ACPI: Added _OSI(Processor Device) [ 0.328016] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.330015] ACPI: Added _OSI(Processor Aggregator Device) [ 0.334816] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.342664] ACPI: Interpreter enabled [ 0.344064] ACPI: PM: (supports S0 S3 S4 S5) [ 0.346013] ACPI: Using IOAPIC for interrupt routing [ 0.348120] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.352449] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.362509] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.365045] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.368017] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.372080] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.379540] acpiphp: Slot [2] registered [ 0.381171] acpiphp: Slot [5] registered [ 0.382195] acpiphp: Slot [6] registered [ 0.384137] acpiphp: Slot [7] registered [ 0.386122] acpiphp: Slot [8] registered [ 0.387100] acpiphp: Slot [9] registered [ 0.388117] acpiphp: Slot [10] registered [ 0.390124] acpiphp: Slot [3] registered [ 0.391109] acpiphp: Slot [4] registered [ 0.393106] acpiphp: Slot [11] registered [ 0.394128] acpiphp: Slot [12] registered [ 0.396120] acpiphp: Slot [13] registered [ 0.397218] acpiphp: Slot [14] registered [ 0.399122] acpiphp: Slot [15] registered [ 0.401116] acpiphp: Slot [16] registered [ 0.402134] acpiphp: Slot [17] registered [ 0.404172] acpiphp: Slot [18] registered [ 0.405111] acpiphp: Slot [19] registered [ 0.407164] acpiphp: Slot [20] registered [ 0.409117] acpiphp: Slot [21] registered [ 0.410114] acpiphp: Slot [22] registered [ 0.412148] acpiphp: Slot [23] registered [ 0.414106] acpiphp: Slot [24] registered [ 0.415100] acpiphp: Slot [25] registered [ 0.416099] acpiphp: Slot [26] registered [ 0.418088] acpiphp: Slot [27] registered [ 0.419091] acpiphp: Slot [28] registered [ 0.420089] acpiphp: Slot [29] registered [ 0.422084] acpiphp: Slot [30] registered [ 0.423112] acpiphp: Slot [31] registered [ 0.425066] PCI host bridge to bus 0000:00 [ 0.426020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.429027] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.431026] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.434038] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.437034] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.439020] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.441206] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.444106] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.447490] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.457837] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.462990] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.465028] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.467016] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.469019] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.472165] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.474795] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.477042] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.479767] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.486015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.500025] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.506021] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.512510] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.524019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.537016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.564022] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.577375] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.585021] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.594024] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.619216] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.632584] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.642023] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.649023] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.665019] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.680983] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.690020] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.697024] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.718027] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.731224] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.741021] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.749020] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.770021] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.779556] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.788024] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.799026] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.824021] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.834000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.838446] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.840430] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.843662] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.846277] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.852115] iommu: Default domain type: Passthrough [ 0.854462] SCSI subsystem initialized [ 0.855106] ACPI: bus type USB registered [ 0.856138] usbcore: registered new interface driver usbfs [ 0.858096] usbcore: registered new interface driver hub [ 0.859079] usbcore: registered new device driver usb [ 0.861167] pps_core: LinuxPPS API ver. 1 registered [ 0.862012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.865085] PTP clock support registered [ 0.866135] EDAC MC: Ver: 3.0.0 [ 0.868135] PCI: Using ACPI for IRQ routing [ 0.870940] NetLabel: Initializing [ 0.872013] NetLabel: domain hash size = 128 [ 0.873012] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.875086] NetLabel: unlabeled traffic allowed by default [ 0.878156] vgaarb: loaded [ 0.879328] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.881022] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.887005] clocksource: Switched to clocksource kvm-clock [ 0.995149] VFS: Disk quotas dquot_6.6.0 [ 0.997199] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.000197] *** VALIDATE ramfs *** [ 1.001624] *** VALIDATE hugetlbfs *** [ 1.003609] pnp: PnP ACPI init [ 1.006563] pnp: PnP ACPI: found 6 devices [ 1.026156] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.029780] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.032694] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.035011] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.037704] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.040069] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.042761] NET: Registered protocol family 2 [ 1.045155] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.050314] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.054387] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.059562] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.063297] TCP: Hash tables configured (established 65536 bind 65536) [ 1.066732] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.069934] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.073250] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.076415] NET: Registered protocol family 1 [ 1.080413] RPC: Registered named UNIX socket transport module. [ 1.083066] RPC: Registered udp transport module. [ 1.084888] RPC: Registered tcp transport module. [ 1.086950] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.089579] NET: Registered protocol family 44 [ 1.091615] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.094185] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.097104] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.099631] PCI: CLS 0 bytes, default 64 [ 1.101559] Unpacking initramfs... [ 2.915748] debug: unmapping init [mem 0xffff8e217cc54000-0xffff8e217ffbffff] [ 2.925692] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.941046] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.961349] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 5.399694] Initialise system trusted keyrings [ 5.403431] Key type blacklist registered [ 5.408108] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 5.514943] zbud: loaded [ 5.534877] *** VALIDATE nfs *** [ 5.536901] *** VALIDATE nfs4 *** [ 5.539823] pstore: using deflate compression [ 5.575658] Platform Keyring initialized [ 6.012527] NET: Registered protocol family 38 [ 6.017365] Key type asymmetric registered [ 6.020702] Asymmetric key parser 'x509' registered [ 6.025954] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 6.030790] io scheduler mq-deadline registered [ 6.033269] io scheduler kyber registered [ 6.037675] io scheduler bfq registered [ 6.040272] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 6.044819] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 6.048604] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 6.052499] ACPI: Power Button [PWRF] [ 6.059617] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 6.067939] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 6.096408] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 6.108113] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 6.142600] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 6.192466] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 6.244802] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 6.264819] Non-volatile memory driver v1.3 [ 6.268702] Linux agpgart interface v0.103 [ 6.359285] virtio_blk virtio1: [vda] 142768 512-byte logical blocks (73.1 MB/69.7 MiB) [ 6.367932] vda: detected capacity change from 0 to 73097216 [ 6.404671] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 6.410989] vdb: detected capacity change from 0 to 1073741824 [ 6.448982] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.457991] vdc: detected capacity change from 0 to 2621440000 [ 6.489111] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.493599] vdd: detected capacity change from 0 to 2621440000 [ 6.525276] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.531546] vde: detected capacity change from 0 to 4294967296 [ 6.566419] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.574115] vdf: detected capacity change from 0 to 4294967296 [ 6.599333] libphy: Fixed MDIO Bus: probed [ 6.619318] usbcore: registered new interface driver usbserial_generic [ 6.627346] usbserial: USB Serial support registered for generic [ 6.639849] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 6.654684] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 6.658284] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 6.662768] mousedev: PS/2 mouse device common for all mice [ 6.667445] rtc_cmos 00:05: RTC can wake from S4 [ 6.674584] rtc_cmos 00:05: registered as rtc0 [ 6.678159] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 6.683681] intel_pstate: CPU model not supported [ 6.699223] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 6.700119] hid: raw HID events driver (C) Jiri Kosina [ 6.723770] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 6.729698] usbcore: registered new interface driver usbhid [ 6.732544] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 6.743966] usbhid: USB HID core driver [ 6.755129] drop_monitor: Initializing network drop monitor service [ 6.768944] Initializing XFRM netlink socket [ 6.775154] NET: Registered protocol family 10 [ 6.789669] Segment Routing with IPv6 [ 6.797630] NET: Registered protocol family 17 [ 6.806372] mpls_gso: MPLS GSO support [ 6.836309] RAS: Correctable Errors collector initialized. [ 6.840230] AVX version of gcm_enc/dec engaged. [ 6.844657] AES CTR mode by8 optimization enabled [ 7.029312] sched_clock: Marking stable (7029279952, 0)->(7921840992, -892561040) [ 7.034980] registered taskstats version 1 [ 7.037962] Loading compiled-in X.509 certificates [ 7.040775] zswap: loaded using pool lzo/zbud [ 7.106817] Key type big_key registered [ 7.133742] Key type encrypted registered [ 7.136959] ima: No TPM chip found, activating TPM-bypass! [ 7.144837] ima: Allocated hash algorithm: sha1 [ 7.147504] ima: No architecture policies found [ 7.150544] evm: Initialising EVM extended attributes: [ 7.156151] evm: security.selinux [ 7.159703] evm: security.ima [ 7.161199] evm: security.capability [ 7.163300] evm: HMAC attrs: 0x1 [ 7.168772] rtc_cmos 00:05: setting system clock to 2026-09-11 07:02:16 UTC (1789110136) [ 7.178217] debug: unmapping init [mem 0xffffffff84e03000-0xffffffff84ffffff] [ 7.182823] debug: unmapping init [mem 0xffffffff83b82000-0xffffffff83e58fff] [ 7.193269] Write protecting the kernel read-only data: 28672k [ 7.200205] debug: unmapping init [mem 0xffffffff82203000-0xffffffff823fffff] [ 7.204292] debug: unmapping init [mem 0xffffffff82b14000-0xffffffff82bfffff] [ 7.323189] 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) [ 7.342941] systemd[1]: Detected virtualization kvm. [ 7.347832] systemd[1]: Detected architecture x86-64. [ 7.349736] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 7.412220] systemd[1]: No hostname configured. [ 7.417863] systemd[1]: Set hostname to . [ 7.420796] random: systemd: uninitialized urandom read (16 bytes read) [ 7.430195] systemd[1]: Initializing machine ID from random generator. [ 7.552100] random: ln: uninitialized urandom read (6 bytes read) [ 7.756081] random: systemd: uninitialized urandom read (16 bytes read) [ 7.766386] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 7.782795] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 7.800374] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on Journal Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Sockets. [ OK ] Reached target Timers. Starting Setup Virtual Console... Starting Journal Service... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 9.795624] device-mapper: uevent: version 1.0.3 [ 9.798626] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 11.346561] random: fast init done [ 11.389176] virtio_net virtio0 ens2: renamed from eth0 [ 11.823368] scsi host0: ata_piix [ 11.985969] scsi host1: ata_piix [ 11.992164] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 11.999201] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 16.674307] random: crng init done [ 16.677362] random: 7 urandom warning(s) missed due to ratelimiting [ 17.039330] dracut-initqueue[585]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 19.412706] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped 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 Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 22.011443] printk: systemd: 26 output lines suppressed due to ratelimiting [ 22.769691] SELinux: Disabled at runtime. [ 22.946308] 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) [ 22.972680] systemd[1]: Detected virtualization kvm. [ 22.979991] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 24.646740] systemd[1]: initrd-switch-root.service: Succeeded. [ 24.653410] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 24.688787] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 24.700494] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 24.705687] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 24.725538] systemd[1]: Starting Journal Service... Starting Journal Service... [ 24.747279] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-getty.slice. Mounting Kernel Debug File System... Mounting Huge Pages File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Kernel Socket. [ OK [ 25.058115] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS ] Started Dispatch Password Requests to Console Directory Watch. 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 ] Stopped target Initrd Root File System. Mounting POSIX Message Queue File System... Starting Apply Kernel Variables... [ OK ] Reached target rpc_pipefs.target. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 26.240272] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 27.244744] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 27.305252] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 27.740568] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 27.819778] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 33.600440] Key type dns_resolver registered [ *** ] A start job is running for Configur…-only root support (9s / no limit)[ 34.367247] NFS: Registering the id_resolver key type [ 34.373894] Key type id_resolver registered [ 34.377671] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (10s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ 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 Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg413-server login: [ 85.710061] hrtimer: interrupt took 2248676 ns [ 95.371429] libcfs: loading out-of-tree module taints kernel. [ 95.424367] Key type ._llcrypt registered [ 95.430646] Key type .llcrypt registered [ 95.629210] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_hostid [ 125.029175] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 126.919173] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 126.929798] alg: No test for adler32 (adler32-zlib) [ 128.736372] Lustre: Lustre: Build Version: 2.17.53_26_gdb05832 [ 130.187132] LNet: Added LNI 192.168.204.113@tcp [8/256/0/180] [ 132.143313] Key type lgssc registered [ 134.670575] Lustre: Echo OBD driver; http://www.lustre.org/ [ 142.085627] alg: No test for zstdfast (zstdfast-lustre-generic) [ 142.102900] alg: No test for zstdfast (zstdfast-lustre-scomp) [ 157.319276] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 209.556964] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 228.665059] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 228.707491] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 230.223993] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 230.279382] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 230.432648] Lustre: lustre-MDT0000: new disk, initializing [ 230.587538] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 230.617718] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 235.583129] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 251.858118] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 251.988477] Lustre: 6577:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 252.014097] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 252.017898] Lustre: Skipped 1 previous similar message [ 252.126104] Lustre: lustre-MDT0001: new disk, initializing [ 252.232242] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 252.272207] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 252.290664] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 258.948200] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 265.648148] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 278.615628] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 279.034849] Lustre: lustre-OST0000: new disk, initializing [ 279.039325] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 279.045457] Lustre: 8480:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 279.131117] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 286.701880] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 287.811437] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 287.835108] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 287.956800] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 304.995897] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 305.183249] Lustre: lustre-OST0001: new disk, initializing [ 305.189321] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 305.197619] Lustre: 9537:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 305.300286] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 312.333386] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 312.342987] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 312.375805] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 313.012034] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 328.733032] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 337.659277] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 346.041726] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing check_logdir /tmp/testlogs/ [ 351.754557] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing yml_node [ 356.648765] Lustre: DEBUG MARKER: Client: 2.17.53.26 [ 359.404418] Lustre: DEBUG MARKER: MDS: 2.17.53.26 [ 362.085342] Lustre: DEBUG MARKER: OSS: 2.17.53.26 [ 363.876257] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Fri Sep 11 03:08:11 EDT 2026 [ 385.166436] Lustre: DEBUG MARKER: excepting tests: [ 398.660757] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 409.568763] 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 [ 409.584953] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 409.624249] Lustre: Skipped 1 previous similar message [ 409.641971] Lustre: Skipped 3 previous similar messages [ 414.692911] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 414.696822] Lustre: Skipped 3 previous similar messages [ 415.710748] Lustre: server umount lustre-MDT0000 complete [ 424.938576] LustreError: 6583: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. [ 424.998727] LustreError: 6583:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 427.505869] LustreError: 6569:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789110556 with bad export cookie 4007831931310991238 [ 427.512751] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 427.522350] LustreError: 6569:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 428.032845] Lustre: server umount lustre-MDT0001 complete [ 446.175164] Lustre: 3660:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110559/real 1789110559] req@ffff8e21c1218000 x1876018079054336/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110575 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 446.207929] 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 [ 446.225033] Lustre: Skipped 2 previous similar messages [ 447.459846] Lustre: server umount lustre-OST0000 complete [ 448.480454] Lustre: 3662:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110561/real 1789110561] req@ffff8e21c1219500 x1876018079054592/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110577 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 451.487327] Lustre: 3661:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110564/real 1789110564] req@ffff8e20c77b8380 x1876018079054848/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110580 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 454.367152] Lustre: 3660:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110567/real 1789110567] req@ffff8e21f4c7d880 x1876018079055232/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110583 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 456.241577] Lustre: server umount lustre-OST0001 complete [ 471.730555] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing unload_modules_local [ 474.659351] Key type lgssc unregistered [ 475.047766] LNet: 14792:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 475.053444] LNetError: 14792:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 475.075826] LNet: Removed LNI 192.168.204.113@tcp [ 476.094160] Key type .llcrypt unregistered [ 476.096111] Key type ._llcrypt unregistered [ 501.383444] Key type ._llcrypt registered [ 501.393761] Key type .llcrypt registered [ 501.513696] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_hostid [ 515.527715] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 516.648850] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 516.714864] alg: No test for adler32 (adler32-zlib) [ 517.681603] Lustre: Lustre: Build Version: 2.17.53_26_gdb05832 [ 517.904635] LNet: Added LNI 192.168.204.113@tcp [8/256/0/180] [ 519.655622] Key type lgssc registered [ 521.138152] Lustre: Echo OBD driver; http://www.lustre.org/ [ 525.041536] alg: No test for zstdfast (zstdfast-lustre-generic) [ 525.127762] alg: No test for zstdfast (zstdfast-lustre-scomp) [ 579.613775] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 597.123891] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 597.143236] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 598.363484] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 598.387353] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 598.447841] Lustre: lustre-MDT0000: new disk, initializing [ 598.542685] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 598.564516] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 602.682517] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 617.396605] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 617.498512] Lustre: 19317:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 617.531611] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 617.535852] Lustre: Skipped 1 previous similar message [ 617.620238] Lustre: lustre-MDT0001: new disk, initializing [ 617.684259] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 617.724489] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 617.730517] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 621.855664] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 626.589722] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 635.328710] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 635.548970] Lustre: lustre-OST0000: new disk, initializing [ 635.553740] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 635.563381] Lustre: 21222:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 635.636167] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 641.042986] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 641.583580] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 641.594666] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 641.662716] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 655.403992] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 655.548049] Lustre: lustre-OST0001: new disk, initializing [ 655.557122] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 655.563537] Lustre: 22228:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 655.644876] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 661.465705] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 662.037770] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 662.064215] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 662.106831] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 671.776355] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 678.199791] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 686.992609] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 03:13:34 (1789110814) === [ 688.931651] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 03:13:36 (1789110816) [ 709.307788] Lustre: Failing over lustre-MDT0000 [ 709.598171] Lustre: server umount lustre-MDT0000 complete [ 710.117359] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 710.131241] 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 [ 713.184648] 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 [ 714.327532] LustreError: 20258:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789110843 with bad export cookie 705936976147084106 [ 714.332303] Lustre: Failing over lustre-MDT0001 [ 714.332859] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 714.341991] LustreError: 20258:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 714.835947] Lustre: server umount lustre-MDT0001 complete [ 724.024093] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 724.451441] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf0890fb300 [ 724.463066] Lustre: MGC192.168.204.113@tcp: Connection restored to 0@lo (at 0@lo) [ 724.783205] LustreError: 21215: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. [ 724.815032] LustreError: 21215:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 724.900610] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 724.938660] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 728.773460] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 730.083895] LustreError: 21216: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. [ 730.089214] 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 [ 730.112412] Lustre: Skipped 2 previous similar messages [ 733.229048] LustreError: 24229: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. [ 733.260290] LustreError: 24229:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 733.265369] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 734.240908] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110847/real 1789110847] req@ffff8e20ccfa9c00 x1876018485917952/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110863 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 735.199119] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110848/real 1789110848] req@ffff8e20c79e2a00 x1876018485918208/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110864 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 735.229253] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 737.306137] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 737.511288] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 737.610941] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 737.640504] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 737.648379] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 739.423316] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110852/real 1789110852] req@ffff8e20cde0dc00 x1876018485918464/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110868 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 739.445408] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 741.701265] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 742.893716] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 742.904128] Lustre: Skipped 1 previous similar message [ 742.911229] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 742.947478] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 742.990824] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 742.991733] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 753.059434] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 03:14:41 (1789110881) [ 773.154814] Lustre: Failing over lustre-MDT0000 [ 773.471457] Lustre: server umount lustre-MDT0000 complete [ 773.601718] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 773.615299] 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 [ 773.634123] Lustre: Skipped 1 previous similar message [ 773.648043] LustreError: 21216: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. [ 777.283028] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789110906 with bad export cookie 705936976147100416 [ 777.284274] Lustre: Failing over lustre-MDT0001 [ 777.285554] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 777.293751] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 777.574458] Lustre: server umount lustre-MDT0001 complete [ 785.230142] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 787.108137] LustreError: 21215: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. [ 787.110540] 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 [ 787.130913] LustreError: 21215:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 787.142093] Lustre: Skipped 4 previous similar messages [ 787.215475] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 787.246873] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 791.175305] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 797.667483] LustreError: 26588: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. [ 797.679293] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 797.685157] LustreError: 26588:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 797.688293] Lustre: Skipped 2 previous similar messages [ 798.687203] Lustre: 16407:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110912/real 1789110912] req@ffff8e20c5a26680 x1876018486035456/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110928 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 798.726910] Lustre: 16407:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 799.068824] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 799.329798] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 799.513282] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 799.515669] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 803.424425] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789110916/real 1789110916] req@ffff8e20cc866d80 x1876018486035840/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789110932 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 803.457579] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 803.573535] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 804.839957] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 804.841234] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 804.854127] Lustre: Skipped 1 previous similar message [ 804.886517] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 804.928839] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 804.934213] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 807.665941] Lustre: *** cfs_fail_loc=193, val=0*** [ 812.261605] Lustre: Failing over lustre-MDT0000 [ 812.555478] Lustre: server umount lustre-MDT0000 complete [ 815.072430] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 815.081832] 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 [ 815.085588] LustreError: 26586: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. [ 815.106110] Lustre: Skipped 3 previous similar messages [ 815.125620] LustreError: 26586:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 820.401167] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 820.558797] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 820.773749] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 820.785035] Lustre: Skipped 1 previous similar message [ 820.816680] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 824.508472] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 825.825251] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 825.832432] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 825.839246] Lustre: Skipped 2 previous similar messages [ 825.856614] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 825.887340] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 825.895354] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 833.066244] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 03:16:00 (1789110960) [ 848.494559] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 868.266243] Lustre: 30408:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 891.531950] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 895.636889] Lustre: 31545:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 909.455784] Lustre: *** cfs_fail_loc=198, val=0*** [ 920.282062] Lustre: Failing over lustre-MDT0000 [ 920.577371] Lustre: server umount lustre-MDT0000 complete [ 923.115575] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 923.119696] 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 [ 923.123967] LustreError: 27221: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. [ 923.123985] LustreError: 27221:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 923.213724] Lustre: Skipped 3 previous similar messages [ 925.054456] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111054 with bad export cookie 705936976147129487 [ 925.057537] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 925.057971] Lustre: Failing over lustre-MDT0001 [ 925.065917] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 925.470746] Lustre: server umount lustre-MDT0001 complete [ 930.534538] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 935.612170] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 944.182925] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 944.607256] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789111057/real 1789111057] req@ffff8e21c6d87480 x1876018486194944/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789111073 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 944.655892] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 950.234246] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 950.268472] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 955.271226] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 963.557062] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 963.565070] Lustre: Skipped 3 previous similar messages [ 964.342471] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 964.626267] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 964.775445] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 964.775935] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 970.216348] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 970.260573] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 970.333445] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 970.337695] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 970.472390] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 985.402730] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 03:18:32 (1789111112) [ 1009.008599] Lustre: Failing over lustre-MDT0000 [ 1009.416546] Lustre: server umount lustre-MDT0000 complete [ 1011.172827] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1011.174449] 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 [ 1011.179880] LustreError: 33020: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. [ 1011.194520] Lustre: Skipped 5 previous similar messages [ 1011.215757] LustreError: 33020:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 17 previous similar messages [ 1013.054277] LustreError: 23038:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111142 with bad export cookie 705936976147156486 [ 1013.056753] Lustre: Failing over lustre-MDT0001 [ 1013.057666] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1013.081039] LustreError: 23038:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1013.426716] Lustre: server umount lustre-MDT0001 complete [ 1017.550951] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1021.665976] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1030.578841] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1030.693438] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 1032.675126] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789111145/real 1789111145] req@ffff8e21f776ad80 x1876018486314752/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789111161 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1032.703235] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1037.857056] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e21f776ad80 x1876018486316800/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1038.202285] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1041.873610] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1050.662454] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1050.710767] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1051.013553] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:233 to 0x280000400:257) [ 1051.015733] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 1052.001929] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1052.003199] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1052.028485] Lustre: Skipped 4 previous similar messages [ 1052.049236] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1052.080152] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 1052.080240] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 1055.455850] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1079.014225] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 1096.529575] Lustre: 38773:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1119.389913] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1123.252860] Lustre: 39909:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1143.832209] Lustre: Failing over lustre-MDT0000 [ 1144.123409] Lustre: server umount lustre-MDT0000 complete [ 1144.288526] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1144.293592] LustreError: Skipped 1 previous similar message [ 1144.299287] 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 [ 1144.313604] Lustre: Skipped 2 previous similar messages [ 1144.323934] LustreError: 21215: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. [ 1144.342334] LustreError: 21215:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 1147.102432] LustreError: 19309:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111276 with bad export cookie 705936976147183940 [ 1147.119912] Lustre: Failing over lustre-MDT0001 [ 1147.122209] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1147.122460] LustreError: 19309:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1147.551298] Lustre: server umount lustre-MDT0001 complete [ 1151.460822] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1159.430432] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1171.690906] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1171.753358] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1172.336109] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1172.341769] Lustre: Skipped 3 previous similar messages [ 1172.378726] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1176.795367] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1184.595527] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1184.651707] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1185.027346] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1185.027617] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1187.061276] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1187.066473] Lustre: Skipped 4 previous similar messages [ 1187.076993] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1187.129754] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1187.179561] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 1187.182237] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 1189.384790] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1210.717648] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 1229.080391] Lustre: 44580:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1252.202540] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1256.115565] Lustre: 45714:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1277.996219] Lustre: Failing over lustre-MDT0000 [ 1278.269953] Lustre: server umount lustre-MDT0000 complete [ 1279.460125] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1279.464825] 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 [ 1279.473888] LustreError: Skipped 1 previous similar message [ 1279.500801] Lustre: Skipped 7 previous similar messages [ 1281.884984] LustreError: 19308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111411 with bad export cookie 705936976147211891 [ 1281.891070] Lustre: Failing over lustre-MDT0001 [ 1281.892236] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1281.919971] LustreError: 19308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1282.246815] Lustre: server umount lustre-MDT0001 complete [ 1286.661441] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1292.860958] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1299.877571] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789111413/real 1789111413] req@ffff8e21ced90700 x1876018486624000/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789111429 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1299.911197] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1301.939202] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1301.969129] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1307.105052] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf08911d3a2 [ 1307.553861] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1311.319741] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1318.896390] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1318.917180] Lustre: Skipped 5 previous similar messages [ 1319.868372] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1319.894311] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1320.276269] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:362 to 0x2c0000400:385) [ 1320.279398] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:361 to 0x280000400:385) [ 1324.676864] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1325.548748] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1325.594025] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1325.640157] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1325.641667] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 1341.104676] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 03:24:29 (1789111469) [ 1354.575542] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 1372.019265] Lustre: 50391:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1391.827584] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1416.694582] Lustre: Failing over lustre-MDT0000 [ 1417.706061] LustreError: 21215: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. [ 1417.726932] LustreError: 21215:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 24 previous similar messages [ 1418.986742] Lustre: server umount lustre-MDT0000 complete [ 1422.353186] LustreError: 19307:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111551 with bad export cookie 705936976147239842 [ 1422.356782] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1422.358931] Lustre: Failing over lustre-MDT0001 [ 1422.362015] LustreError: 19307:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1422.702653] Lustre: server umount lustre-MDT0001 complete [ 1427.414470] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1435.921140] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1439.135363] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789111552/real 1789111552] req@ffff8e20c5a27b80 x1876018486777856/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789111568 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1439.168841] Lustre: 16405:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 1442.456464] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1450.178105] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1459.712519] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1459.730562] Lustre: lustre-MDT0000: reset Object Index mappings [ 1466.850284] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf0891240d1 [ 1467.202394] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1467.209510] Lustre: Skipped 3 previous similar messages [ 1467.245181] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1471.115735] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1478.991266] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1479.021134] Lustre: lustre-MDT0001: reset Object Index mappings [ 1479.347325] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1479.353282] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 1483.431389] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1483.452366] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1483.470755] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1483.509848] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 1483.509903] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 1494.428424] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 03:27:02 (1789111622) [ 1515.316853] Lustre: Failing over lustre-MDT0000 [ 1515.572278] Lustre: server umount lustre-MDT0000 complete [ 1519.206142] LustreError: 23038:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111648 with bad export cookie 705936976147267793 [ 1519.210020] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1519.212695] Lustre: Failing over lustre-MDT0001 [ 1519.218524] LustreError: 23038:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1519.592309] Lustre: server umount lustre-MDT0001 complete [ 1524.916515] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1534.399477] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1535.839182] 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 [ 1535.860914] Lustre: Skipped 12 previous similar messages [ 1543.719353] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1554.408991] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1566.648211] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1566.690084] Lustre: lustre-MDT0000: reset Object Index mappings [ 1589.613581] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1592.884532] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1601.328034] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1601.349630] Lustre: lustre-MDT0001: reset Object Index mappings [ 1601.580261] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1601.595137] LustreError: Skipped 3 previous similar messages [ 1601.737709] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1601.752082] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:489 to 0x280000400:513) [ 1604.770341] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1604.777377] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1604.802922] Lustre: Skipped 10 previous similar messages [ 1604.841446] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1604.892886] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:521 to 0x280000401:545) [ 1604.893224] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1606.105602] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1612.413320] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64002: rc = 0 [ 1613.558043] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32038 with flags 0x52: rc = 0 [ 1634.168512] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 03:29:22 (1789111762) [ 1654.312713] Lustre: Failing over lustre-MDT0000 [ 1654.827830] Lustre: server umount lustre-MDT0000 complete [ 1658.994879] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789111788 with bad export cookie 705936976147295513 [ 1658.997062] Lustre: Failing over lustre-MDT0001 [ 1659.002910] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1659.009964] LustreError: 25716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1659.663143] Lustre: server umount lustre-MDT0001 complete [ 1665.064629] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1674.013543] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1677.727381] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789111791/real 1789111791] req@ffff8e21cecf4000 x1876018487023360/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789111807 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1677.763258] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 1681.797079] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1691.408365] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1701.817283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1701.832198] Lustre: lustre-MDT0000: reset Object Index mappings [ 1703.967241] LustreError: 62482:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 1703.985176] LustreError: 62482:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8e21f486b480 x1876018487025792/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1789111833 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1704.004301] LustreError: 62482:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 1708.692467] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1717.279320] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1717.300711] Lustre: lustre-MDT0001: reset Object Index mappings [ 1717.704766] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 1717.706484] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:553 to 0x280000400:577) [ 1721.653661] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1721.831310] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 1721.831957] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:585 to 0x280000401:609) [ 1728.814779] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/64002: rc = 0 [ 1732.037666] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32038 with flags 0x52: rc = 0 [ 1848.026724] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 03:32:56 (1789111976) [ 1877.768289] Lustre: Failing over lustre-MDT0000 [ 1878.075040] Lustre: server umount lustre-MDT0000 complete [ 1881.522548] LustreError: 19308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789112010 with bad export cookie 705936976147322918 [ 1881.530869] Lustre: Failing over lustre-MDT0001 [ 1881.536736] LustreError: 19308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1881.569769] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1881.574277] Lustre: Skipped 1 previous similar message [ 1881.784984] Lustre: server umount lustre-MDT0001 complete [ 1886.923951] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1897.776158] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1907.052281] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1916.858748] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1927.400054] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1927.435184] Lustre: lustre-MDT0000: reset Object Index mappings [ 1951.615275] LustreError: 25265: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. [ 1951.628371] LustreError: 25265:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 22 previous similar messages [ 1951.760717] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1951.776235] Lustre: Skipped 1 previous similar message [ 1956.777172] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1966.968127] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1967.020315] Lustre: lustre-MDT0001: reset Object Index mappings [ 1967.466498] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:617 to 0x280000400:641) [ 1967.468242] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 1972.514124] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1972.550174] Lustre: Skipped 1 previous similar message [ 1972.595458] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1972.604716] Lustre: Skipped 1 previous similar message [ 1972.665261] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 1972.668392] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 1973.019990] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1981.964346] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/64001: rc = 0 [ 1985.327509] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32033 with flags 0x52: rc = 0 [ 2070.239792] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 03:36:37 (1789112197) [ 2086.556209] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2086.558235] Lustre: Skipped 1 previous similar message [ 2087.066405] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2087.068364] Lustre: Skipped 55 previous similar messages [ 2088.087370] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2088.089400] Lustre: Skipped 223 previous similar messages [ 2103.573450] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 03:37:11 (1789112231) [ 2108.000279] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2108.002404] Lustre: Skipped 175 previous similar messages [ 2108.340120] LustreError: 65367:0:(osd_compat.c:736:osd_obj_update_entry()) lustre-OST0000: the FID [0x280000401:0x321:0x0] is used by two objects: 266/3277319453 218/2174980118 [ 2120.921044] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 03:37:28 (1789112248) [ 2136.549922] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2136.552753] 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 [ 2136.557540] LustreError: Skipped 4 previous similar messages [ 2136.575794] Lustre: Skipped 12 previous similar messages [ 2136.581821] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2141.665393] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2141.673200] Lustre: Skipped 6 previous similar messages [ 2146.791477] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2146.800680] Lustre: Skipped 2 previous similar messages [ 2150.369057] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2150.593934] Lustre: server umount lustre-MDT0000 complete [ 2154.814894] LustreError: 19307:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789112284 with bad export cookie 705936976147367116 [ 2154.815540] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2154.827580] LustreError: 19307:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2154.835515] LustreError: Skipped 1 previous similar message [ 2157.028743] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2157.035428] Lustre: Skipped 1 previous similar message [ 2165.216113] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2165.230304] Lustre: Skipped 5 previous similar messages [ 2169.311182] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2169.678537] Lustre: server umount lustre-MDT0001 complete [ 2179.723628] Lustre: server umount lustre-OST0000 complete [ 2189.798262] Lustre: server umount lustre-OST0001 complete [ 2196.589340] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_hostid [ 2204.002426] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 2252.357157] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 2265.616031] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2266.033208] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2266.063106] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2266.158927] Lustre: lustre-MDT0000: new disk, initializing [ 2266.275100] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2266.278876] Lustre: Skipped 7 previous similar messages [ 2266.291798] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2270.107815] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2280.340876] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2280.440486] Lustre: 75397:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2280.449385] Lustre: 75397:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 2280.482183] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2280.488870] Lustre: Skipped 1 previous similar message [ 2280.576296] Lustre: lustre-MDT0001: new disk, initializing [ 2280.674394] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2280.684819] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2284.539727] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2289.504397] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2295.764929] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2296.059368] Lustre: lustre-OST0000: new disk, initializing [ 2296.069374] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2296.079894] Lustre: 76998:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2298.007995] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2298.022764] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2298.135458] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2302.252706] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2313.197670] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2313.414510] Lustre: lustre-OST0001: new disk, initializing [ 2313.419364] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2313.424890] Lustre: 77851:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2314.588351] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2314.602349] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2314.717822] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2319.973652] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2329.656788] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2334.021929] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2359.950763] Lustre: Failing over lustre-MDT0000 [ 2360.314640] Lustre: server umount lustre-MDT0000 complete [ 2364.199050] Lustre: Failing over lustre-MDT0001 [ 2364.594629] Lustre: server umount lustre-MDT0001 complete [ 2369.852225] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2379.015281] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2382.306287] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789112495/real 1789112495] req@ffff8e21cecf4380 x1876018487517440/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789112511 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2382.338994] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 2387.489983] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2399.382618] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2412.179179] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2412.228285] Lustre: lustre-MDT0000: reset Object Index mappings [ 2434.591623] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e20c6618a80 x1876018487521152/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2435.072947] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2439.127925] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2446.699901] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2447.029821] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2447.083349] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 2447.084220] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2451.178102] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2451.190534] Lustre: Skipped 14 previous similar messages [ 2451.192632] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2451.210904] Lustre: lustre-MDT0000: Recovery over after 0:04, of 1 clients 1 recovered and 0 were evicted. [ 2451.254046] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 2451.261629] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 2460.268559] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/96003: rc = 0 [ 2460.268584] Lustre: *** cfs_fail_loc=190, val=3*** [ 2461.308784] Lustre: *** cfs_fail_loc=190, val=3*** [ 2461.312481] Lustre: Skipped 1 previous similar message [ 2462.346878] Lustre: *** cfs_fail_loc=190, val=3*** [ 2463.539045] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/34 with flags 0x52: rc = 0 [ 2465.375915] Lustre: *** cfs_fail_loc=190, val=3*** [ 2465.385314] Lustre: Skipped 2 previous similar messages [ 2469.669460] Lustre: *** cfs_fail_loc=191, val=3*** [ 2469.674128] Lustre: Skipped 2 previous similar messages [ 2474.940087] Lustre: Failing over lustre-MDT0000 [ 2475.124891] Lustre: server umount lustre-MDT0000 complete [ 2478.767339] Lustre: Failing over lustre-MDT0001 [ 2479.284806] Lustre: server umount lustre-MDT0001 complete [ 2488.882942] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2489.312756] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf089158574 [ 2494.297256] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2505.566337] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2506.419839] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2506.430201] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:97) [ 2511.455213] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:97) [ 2511.463040] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:97) [ 2511.928906] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2519.248275] Lustre: Failing over lustre-MDT0000 [ 2519.563163] Lustre: server umount lustre-MDT0000 complete [ 2524.025877] Lustre: Failing over lustre-MDT0001 [ 2524.306153] Lustre: server umount lustre-MDT0001 complete [ 2536.695514] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2536.796264] Lustre: *** cfs_fail_loc=190, val=3*** [ 2536.801192] Lustre: Skipped 1 previous similar message [ 2549.221622] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf089158bd3 [ 2552.673048] LustreError: 85551: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. [ 2552.682906] LustreError: 85551:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 44 previous similar messages [ 2554.353674] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2554.918937] Lustre: *** cfs_fail_loc=190, val=3*** [ 2554.921034] Lustre: Skipped 5 previous similar messages [ 2563.841609] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2564.272915] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:129) [ 2564.297135] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2568.836781] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2569.770893] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:129) [ 2569.771494] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:129) [ 2582.980893] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/114: rc = 0 [ 2583.024863] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/34 with flags 0x52: rc = 0 [ 2594.684729] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 03:45:22 (1789112722) [ 2620.619487] Lustre: Failing over lustre-MDT0000 [ 2620.931201] Lustre: server umount lustre-MDT0000 complete [ 2624.971901] Lustre: Failing over lustre-MDT0001 [ 2625.434993] Lustre: server umount lustre-MDT0001 complete [ 2631.327571] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2642.522514] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2653.381804] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2665.176459] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2677.013031] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2677.042565] Lustre: lustre-MDT0000: reset Object Index mappings [ 2677.048869] Lustre: Skipped 1 previous similar message [ 2695.648808] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e20c10d0380 x1876018487706752/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2700.669736] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2709.177598] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2709.588553] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2709.599113] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2711.697050] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 2711.698361] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 2714.137708] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2722.321511] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32004: rc = 0 [ 2722.321428] Lustre: *** cfs_fail_loc=190, val=2*** [ 2722.337390] Lustre: Skipped 12 previous similar messages [ 2725.534341] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/64024 with flags 0x52: rc = 0 [ 2752.689623] Lustre: Failing over lustre-MDT0000 [ 2753.001233] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2753.012957] LustreError: Skipped 7 previous similar messages [ 2753.016490] 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 [ 2753.029457] Lustre: Skipped 27 previous similar messages [ 2753.076393] Lustre: server umount lustre-MDT0000 complete [ 2756.012916] LustreError: 77862:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789112885 with bad export cookie 705936976147524973 [ 2756.017663] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2756.017956] Lustre: Failing over lustre-MDT0001 [ 2756.024432] LustreError: 77862:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 16 previous similar messages [ 2756.041389] LustreError: Skipped 4 previous similar messages [ 2756.439544] Lustre: server umount lustre-MDT0001 complete [ 2765.653859] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2781.152674] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf0891634dd [ 2786.911278] Lustre: *** cfs_fail_loc=190, val=3*** [ 2786.913136] Lustre: Skipped 31 previous similar messages [ 2787.864509] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2797.017363] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2797.499673] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2797.505772] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2802.000145] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2802.740515] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:225) [ 2802.745900] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 2824.370381] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 03:49:12 (1789112952) [ 2840.704737] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 2859.991571] Lustre: 95803:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2882.704288] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2886.466897] Lustre: 96941:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2926.970885] Lustre: Failing over lustre-MDT0000 [ 2929.310091] Lustre: server umount lustre-MDT0000 complete [ 2933.721727] Lustre: Failing over lustre-MDT0001 [ 2934.311443] Lustre: server umount lustre-MDT0001 complete [ 2940.860530] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2950.977268] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2952.172672] Lustre: 16407:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789113065/real 1789113065] req@ffff8e21c483ce00 x1876018487904256/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789113081 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2952.214866] Lustre: 16407:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 55 previous similar messages [ 2959.804477] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2970.137171] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2981.825255] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2981.856322] Lustre: lustre-MDT0000: reset Object Index mappings [ 2981.859289] Lustre: Skipped 1 previous similar message [ 3004.956757] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3004.969961] Lustre: Skipped 13 previous similar messages [ 3005.034397] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3005.044380] Lustre: Skipped 4 previous similar messages [ 3010.115336] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3020.214091] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3020.860680] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:265 to 0x2c0000400:289) [ 3020.889205] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 3021.813614] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3021.821050] Lustre: Skipped 4 previous similar messages [ 3021.855823] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3021.865942] Lustre: Skipped 4 previous similar messages [ 3021.901614] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3021.902434] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 3025.578179] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3033.769468] Lustre: *** cfs_fail_loc=190, val=3*** [ 3033.769621] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32009: rc = 0 [ 3033.774343] Lustre: Skipped 12 previous similar messages [ 3033.797905] Lustre: Skipped 2 previous similar messages [ 3037.096128] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/128022 with flags 0x52: rc = 0 [ 3056.542741] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 03:53:04 (1789113184) [ 3095.641183] Lustre: Failing over lustre-MDT0000 [ 3095.900543] Lustre: server umount lustre-MDT0000 complete [ 3099.728454] Lustre: Failing over lustre-MDT0001 [ 3100.075318] Lustre: server umount lustre-MDT0001 complete [ 3105.734805] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3116.811376] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3125.883264] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3136.428060] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3149.772258] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3170.338955] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf0891856c8 [ 3170.360400] Lustre: MGC192.168.204.113@tcp: Connection restored to 0@lo (at 0@lo) [ 3170.373634] Lustre: Skipped 32 previous similar messages [ 3170.612629] LustreError: 76993: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. [ 3170.655188] LustreError: 76993:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 41 previous similar messages [ 3174.999754] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3183.237180] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3183.663123] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 3183.688294] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:329 to 0x2c0000400:353) [ 3188.078298] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3188.756315] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 3188.756398] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 3225.154513] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 03:55:53 (1789113353) [ 3239.478870] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 3258.270873] Lustre: 108403:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3284.060690] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3410.315473] Lustre: Failing over lustre-MDT0000 [ 3411.111422] Lustre: server umount lustre-MDT0000 complete [ 3413.985558] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3414.004489] LustreError: Skipped 5 previous similar messages [ 3414.019818] 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 [ 3414.043961] Lustre: Skipped 17 previous similar messages [ 3414.988269] LustreError: 87433:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789113544 with bad export cookie 705936976147666632 [ 3414.991270] Lustre: Failing over lustre-MDT0001 [ 3414.995467] LustreError: 87433:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3414.995803] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3414.995807] LustreError: Skipped 2 previous similar messages [ 3415.016479] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3415.024591] Lustre: Skipped 1 previous similar message [ 3415.779549] Lustre: server umount lustre-MDT0001 complete [ 3420.900308] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3432.456251] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3443.142520] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3455.443493] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3472.092574] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3485.608845] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf0891b8919 [ 3490.632491] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3499.214632] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3499.244510] Lustre: lustre-MDT0001: reset Object Index mappings [ 3499.254115] Lustre: Skipped 4 previous similar messages [ 3499.663582] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:393 to 0x2c0000400:417) [ 3499.669566] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 3503.810721] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3503.811692] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 3504.178764] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3563.761384] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 04:01:31 (1789113691) [ 3579.492698] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 3596.586994] Lustre: 116337:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3596.595985] Lustre: 116337:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 3618.310447] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3767.555797] Lustre: Failing over lustre-MDT0000 [ 3767.816542] Lustre: server umount lustre-MDT0000 complete [ 3771.610868] Lustre: Failing over lustre-MDT0001 [ 3772.263207] Lustre: server umount lustre-MDT0001 complete [ 3778.105395] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3788.219159] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3790.816419] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789113904/real 1789113904] req@ffff8e20c461dc00 x1876018488484480/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789113920 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3790.868720] Lustre: 16406:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 3797.501293] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3807.522511] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3819.683636] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3841.056085] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e20d394dc00 x1876018488488192/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3841.484409] LustreError: 76992: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. [ 3841.505502] LustreError: 76992:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 3841.592457] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3841.600642] Lustre: Skipped 5 previous similar messages [ 3841.673244] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3841.689055] Lustre: Skipped 2 previous similar messages [ 3846.150846] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3854.920297] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3855.276881] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:481) [ 3855.315742] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:481) [ 3859.445837] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3860.386759] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3860.397705] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3860.401082] Lustre: Skipped 2 previous similar messages [ 3860.427528] Lustre: Skipped 11 previous similar messages [ 3860.499697] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3860.515103] Lustre: Skipped 2 previous similar messages [ 3860.581757] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 3860.582383] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 3868.306378] Lustre: *** cfs_fail_loc=190, val=1*** [ 3868.307829] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64002: rc = 0 [ 3868.312107] Lustre: Skipped 40 previous similar messages [ 3871.648505] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32028 with flags 0x52: rc = 0 [ 3878.957256] Lustre: Failing over lustre-MDT0000 [ 3881.309927] Lustre: server umount lustre-MDT0000 complete [ 3885.643125] Lustre: Failing over lustre-MDT0001 [ 3886.171821] Lustre: server umount lustre-MDT0001 complete [ 3897.451817] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3910.498503] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x9cbfdf089263fd0 [ 3916.314763] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3927.088114] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3927.620552] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:513) [ 3927.620558] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:513) [ 3931.235219] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3932.723044] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:513) [ 3932.725621] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 3936.306479] Lustre: Failing over lustre-MDT0000 [ 3936.568240] Lustre: server umount lustre-MDT0000 complete [ 3939.808946] Lustre: Failing over lustre-MDT0001 [ 3940.118118] Lustre: server umount lustre-MDT0001 complete [ 3948.305497] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3954.982861] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3963.880593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3964.120251] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:457 to 0x2c0000400:545) [ 3964.129827] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:458 to 0x280000400:545) [ 3969.545743] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3969.606164] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:545) [ 3969.606877] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 3986.251829] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 04:08:34 (1789114114) [ 4001.577343] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 4021.358305] Lustre: 127249:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4021.364727] Lustre: 127249:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 4046.536628] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4077.362827] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 04:10:05 (1789114205) [ 4082.718733] Lustre: *** cfs_fail_loc=195, val=0*** [ 4083.390651] Lustre: *** cfs_fail_loc=195, val=0*** [ 4083.393888] Lustre: Skipped 31 previous similar messages [ 4088.864334] Lustre: Failing over lustre-OST0000 [ 4089.096117] Lustre: server umount lustre-OST0000 complete [ 4092.390631] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4092.394429] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4092.404481] LustreError: Skipped 7 previous similar messages [ 4092.423112] Lustre: Skipped 23 previous similar messages [ 4098.214475] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4105.860041] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4297.911757] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 04:13:45 (1789114425) [ 4302.260277] Lustre: *** cfs_fail_loc=196, val=0*** [ 4302.268416] Lustre: Skipped 31 previous similar messages [ 4308.297203] Lustre: Failing over lustre-OST0000 [ 4308.410589] Lustre: server umount lustre-OST0000 complete [ 4316.680781] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4323.029763] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4513.603458] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 04:17:21 (1789114641) [ 4519.833703] Lustre: *** cfs_fail_loc=196, val=0*** [ 4519.839687] Lustre: Skipped 63 previous similar messages [ 4524.301288] Lustre: *** cfs_fail_loc=196, val=0*** [ 4524.306327] Lustre: Skipped 383 previous similar messages [ 4538.654698] Lustre: Failing over lustre-OST0000 [ 4539.003138] Lustre: server umount lustre-OST0000 complete [ 4542.437865] LustreError: 76980: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. [ 4542.455834] LustreError: 76980:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 41 previous similar messages [ 4549.686044] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4550.017203] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4550.037498] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4550.052597] Lustre: Skipped 4 previous similar messages [ 4551.205482] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4551.212846] Lustre: Skipped 4 previous similar messages [ 4551.259130] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4551.262670] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4551.270240] Lustre: Skipped 4 previous similar messages [ 4551.281572] Lustre: Skipped 19 previous similar messages [ 4557.100379] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4568.545353] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4570.598768] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4574.761280] Lustre: server umount lustre-MDT0000 complete [ 4578.873158] LustreError: 75391:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789114708 with bad export cookie 705936976148579887 [ 4578.878610] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4578.887279] LustreError: 75391:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 15 previous similar messages [ 4578.893450] LustreError: Skipped 3 previous similar messages [ 4579.206564] Lustre: server umount lustre-MDT0001 complete [ 4593.768223] Lustre: server umount lustre-OST0000 complete [ 4597.663107] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789114710/real 1789114710] req@ffff8e21d021f100 x1876018488981120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789114726 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4597.732153] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 32 previous similar messages [ 4598.087206] Lustre: server umount lustre-OST0001 complete [ 4609.850157] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 04:18:57 (1789114737) [ 4626.609566] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_hostid [ 4635.315149] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 4681.380977] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 4691.676311] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4691.982106] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4692.022569] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4692.081863] Lustre: lustre-MDT0000: new disk, initializing [ 4692.183370] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4692.192372] Lustre: Skipped 7 previous similar messages [ 4692.207388] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4696.357575] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4706.775160] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4706.850490] Lustre: 138486:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 4706.858229] Lustre: 138486:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 4706.876782] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4706.881844] Lustre: Skipped 1 previous similar message [ 4706.976855] Lustre: lustre-MDT0001: new disk, initializing [ 4707.083445] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4707.101398] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4710.958559] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4716.610807] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4723.845513] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4724.119233] Lustre: lustre-OST0000: new disk, initializing [ 4724.124900] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4724.133196] Lustre: 140083:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4725.753457] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4725.767330] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4725.849593] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4731.208712] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4744.057491] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4744.223806] Lustre: lustre-OST0001: new disk, initializing [ 4744.237133] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4744.245577] Lustre: 140936:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4745.524094] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4745.534231] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4745.651567] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4752.010718] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4761.868907] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4766.067606] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4787.508969] Lustre: Failing over lustre-MDT0000 [ 4787.926397] Lustre: server umount lustre-MDT0000 complete [ 4789.215595] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4789.220715] LustreError: Skipped 1 previous similar message [ 4789.231280] 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 [ 4789.250768] Lustre: Skipped 9 previous similar messages [ 4791.486345] Lustre: Failing over lustre-MDT0001 [ 4791.790207] Lustre: server umount lustre-MDT0001 complete [ 4797.862358] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4810.435956] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4821.413978] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4834.456423] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4846.595448] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4846.627669] Lustre: lustre-MDT0000: reset Object Index mappings [ 4846.634379] Lustre: Skipped 2 previous similar messages [ 4861.407906] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e21de57c000 x1876018489101824/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4866.637348] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4877.632772] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4878.345347] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 4878.353287] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 4879.454060] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 4879.457770] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 4883.114439] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4931.467871] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 04:24:19 (1789115059) [ 4944.343880] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 4983.158362] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5009.890900] Lustre: Failing over lustre-MDT0000 [ 5009.906913] Lustre: *** cfs_fail_loc=199, val=0*** [ 5009.914897] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5009.930654] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5009.944652] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5009.953987] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5009.961434] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5009.970836] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5009.982945] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5010.000399] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5010.006744] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5010.013451] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5010.022659] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5010.028607] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5010.041970] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5010.049846] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5010.056432] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5010.063753] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5010.070994] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5010.078757] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5010.085855] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5010.094576] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5010.101980] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5010.109588] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5010.117785] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5010.124944] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5010.132721] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5010.145973] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5010.154217] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5010.162625] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5010.170314] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5010.177415] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5010.185750] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5010.200654] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5010.229105] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5010.248648] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5010.266816] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5010.275641] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5010.282190] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5010.295050] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5010.330977] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5010.349481] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5010.360818] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5010.377805] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5010.389869] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5010.401697] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5010.419611] Lustre: *** cfs_fail_loc=199, val=0*** [ 5010.426478] Lustre: Skipped 43 previous similar messages [ 5010.431911] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5010.450238] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5010.471972] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5010.488871] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5010.499291] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5010.517138] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5010.526670] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5010.539760] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5010.550441] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5010.567356] Lustre: 150627:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5010.918051] Lustre: server umount lustre-MDT0000 complete [ 5014.753398] Lustre: Failing over lustre-MDT0001 [ 5014.769412] Lustre: *** cfs_fail_loc=199, val=0*** [ 5014.778667] Lustre: Skipped 9 previous similar messages [ 5014.782178] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5014.789695] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5014.808654] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5014.821800] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5014.838183] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5014.854584] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5014.862321] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5014.871151] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5014.876822] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5014.883786] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5014.889692] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5014.896789] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5014.909578] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5014.919161] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5014.927144] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5014.937510] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5014.948365] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5014.959694] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5014.966188] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5014.975901] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5014.989322] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5015.001209] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5015.012468] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5015.028412] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5015.043951] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5015.054799] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5015.064967] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5015.073667] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5015.081385] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5015.089829] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5015.098136] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5015.107807] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5015.124549] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5015.132752] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5015.139800] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5015.150376] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5015.160497] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5015.169153] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5015.178996] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5015.186230] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5015.195234] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5015.204891] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5015.212459] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5015.218719] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5015.229353] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5015.237261] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5015.244847] Lustre: 150828:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5015.628195] Lustre: server umount lustre-MDT0001 complete [ 5025.172105] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5025.298324] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5025.307845] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5025.318325] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5025.331446] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5025.340112] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5025.357424] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5025.368846] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5025.380909] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5025.388688] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5025.395697] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5025.410631] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5025.421270] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5025.440423] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5025.457979] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5025.476685] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5025.500397] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5025.517161] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5025.531857] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5025.549244] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5025.572054] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5025.591266] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5025.606988] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5025.625299] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5025.651778] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5025.667797] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5025.685917] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5025.701592] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5025.718601] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5025.727686] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5025.738986] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5025.749521] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5025.763421] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5025.784839] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5025.805381] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5025.818146] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5025.843987] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5025.857312] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5025.870678] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5025.881890] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5025.899413] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5025.912969] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5025.926187] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5025.938434] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5025.947791] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5025.975497] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5025.995686] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5026.022134] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5026.037744] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5026.048654] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5026.060172] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5026.069450] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5026.077505] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5026.085677] Lustre: 151326:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5040.031758] LustreError: 16403:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8e20c4675f80 x1876018489265408/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5045.070299] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5054.895718] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5055.028861] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5055.038330] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5055.047975] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5055.057760] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5055.076054] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5055.085988] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5055.094267] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5055.103899] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5055.114408] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5055.127237] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5055.142642] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5055.160227] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5055.170330] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5055.213516] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5055.227812] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5055.255890] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5055.280490] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5055.302936] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5055.322590] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5055.341256] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5055.370514] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5055.392973] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5055.406924] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5055.425469] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5055.450121] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5055.477554] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5055.490738] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5055.505501] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5055.516906] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5055.528325] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5055.536736] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5055.549623] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5055.563458] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5055.583136] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5055.593328] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5055.604461] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5055.623191] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5055.643759] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5055.653555] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5055.665223] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5055.675475] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5055.685593] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5055.693948] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5055.707840] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5055.725089] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5055.738156] Lustre: 152055:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5056.118588] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 5056.140461] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 5060.756756] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5061.167153] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5061.173323] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 5072.147654] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 04:26:40 (1789115200) [ 5073.012322] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5073.015803] Lustre: Skipped 123 previous similar messages [ 5074.544273] Lustre: Failing over lustre-MDT0000 [ 5074.786893] Lustre: server umount lustre-MDT0000 complete [ 5090.323145] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5095.298269] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5096.016246] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 5096.016444] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5098.994562] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 04:27:06 (1789115226) [ 5100.084556] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5101.570908] Lustre: Failing over lustre-MDT0000 [ 5101.891525] Lustre: server umount lustre-MDT0000 complete [ 5117.700977] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5123.167852] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5123.631686] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 5123.631727] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5126.689957] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 04:27:34 (1789115254) [ 5146.105151] Lustre: Failing over lustre-MDT0000 [ 5146.503811] Lustre: server umount lustre-MDT0000 complete [ 5149.156493] LustreError: 152075: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. [ 5149.170184] LustreError: 152075:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 58 previous similar messages [ 5149.962043] Lustre: Failing over lustre-MDT0001 [ 5150.370246] Lustre: server umount lustre-MDT0001 complete [ 5158.100795] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5160.287144] LustreError: 156041:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 5160.296421] LustreError: 156041:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8e20c92f9500 x1876018489423744/t0(0) o250->MGC192.168.204.113@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1789115289 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_02.0' uid:0 gid:0 projid:4294967295 [ 5160.316110] LustreError: 156041:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 5160.711197] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5160.723106] Lustre: Skipped 4 previous similar messages [ 5164.871662] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5169.196375] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5169.200985] Lustre: Skipped 19 previous similar messages [ 5174.092896] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5174.469893] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 5174.469331] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 5179.537821] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5179.877706] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5179.897455] Lustre: Skipped 4 previous similar messages [ 5179.919910] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5179.928778] Lustre: Skipped 4 previous similar messages [ 5180.015093] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 5180.018225] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5187.499496] Lustre: Failing over lustre-MDT0000 [ 5187.831723] Lustre: server umount lustre-MDT0000 complete [ 5192.102211] Lustre: Failing over lustre-MDT0001 [ 5192.104644] LustreError: 138479:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789115321 with bad export cookie 705936976148774872 [ 5192.106920] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5192.106928] LustreError: Skipped 5 previous similar messages [ 5192.140434] LustreError: 138479:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 5192.467983] Lustre: server umount lustre-MDT0001 complete [ 5202.283685] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5202.297275] Lustre: lustre-MDT0000: reset Object Index mappings [ 5202.299642] Lustre: Skipped 1 previous similar message [ 5207.137692] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5211.114179] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789115324/real 1789115324] req@ffff8e20c92f9c00 x1876018489453056/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789115340 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5211.166319] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 35 previous similar messages [ 5215.508090] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5215.817184] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 5215.825329] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 5219.752259] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5220.939214] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5220.945116] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:289) [ 5230.030663] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 04:29:17 (1789115357) [ 5241.317437] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5241.321444] Lustre: Skipped 6 previous similar messages [ 5245.227665] Lustre: server umount lustre-MDT0000 complete [ 5249.613434] Lustre: server umount lustre-MDT0001 complete [ 5263.459561] Lustre: server umount lustre-OST0000 complete [ 5277.717538] Lustre: server umount lustre-OST0001 complete [ 5285.090410] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5294.304398] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5309.856769] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5314.975575] LustreError: 160707:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.113@tcp: failed processing log, type 4: rc = -110 [ 5340.575200] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5340.580941] Lustre: Skipped 13 previous similar messages [ 5346.260480] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5352.209699] Lustre: Failing over lustre-OST0000 [ 5352.474836] Lustre: server umount lustre-OST0000 complete [ 5358.665314] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5367.610785] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5383.135838] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5388.255340] LustreError: 162216:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.113@tcp: failed processing log, type 4: rc = -110 [ 5420.279449] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5429.094100] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 04:32:36 (1789115556) [ 5444.271682] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 5454.916549] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5455.559647] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5460.205837] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5467.583182] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5467.889528] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:257) [ 5471.440984] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5474.221232] Lustre: 165066:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5474.231328] Lustre: 165066:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 2 previous similar messages [ 5488.200672] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5493.745263] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 5493.748761] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 5493.996707] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5501.734790] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5507.668842] Lustre: *** cfs_fail_loc=193, val=0*** [ 5509.679742] Lustre: Failing over lustre-MDT0000 [ 5509.837142] Lustre: *** cfs_fail_loc=193, val=0*** [ 5510.038693] Lustre: server umount lustre-MDT0000 complete [ 5514.208492] 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 [ 5514.210709] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5514.225576] Lustre: Skipped 35 previous similar messages [ 5514.245400] LustreError: Skipped 9 previous similar messages [ 5519.925700] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5520.463309] Lustre: *** cfs_fail_loc=193, val=0*** [ 5525.812125] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5526.075659] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 5526.079611] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5529.757990] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5529.761796] Lustre: Skipped 4 previous similar messages [ 5529.774238] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5529.777287] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5529.792364] Lustre: Skipped 65 previous similar messages [ 5543.654041] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 04:34:31 (1789115671) [ 5546.873912] Lustre: Failing over lustre-MDT0000 [ 5547.177533] Lustre: server umount lustre-MDT0000 complete [ 5551.720869] Lustre: Failing over lustre-MDT0001 [ 5552.381590] Lustre: server umount lustre-MDT0001 complete [ 5555.724522] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5563.510801] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5581.914228] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5590.137704] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5592.576660] LustreError: 169521:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5592.664377] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:289) [ 5592.664461] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 5592.696287] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 5592.711783] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5594.964584] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5600.050722] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5606.136602] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 04:35:34 (1789115734) [ 5613.026452] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5613.043737] Lustre: Skipped 1 previous similar message [ 5618.542741] Lustre: server umount lustre-MDT0000 complete [ 5622.578706] Lustre: server umount lustre-MDT0001 complete [ 5637.292815] Lustre: server umount lustre-OST0000 complete [ 5641.103400] Lustre: server umount lustre-OST0001 complete [ 5648.681231] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5662.566902] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5668.655284] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5675.045929] Lustre: Failing over lustre-MDT0000 [ 5675.053796] LustreError: 171878:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5675.074682] LustreError: 171878:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5675.087993] LustreError: 171878:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 12, retries 0, failed: rc = -5 [ 5675.672035] Lustre: server umount lustre-MDT0000 complete [ 5683.616225] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5697.065871] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5702.009041] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5709.797095] Lustre: DEBUG MARKER: === sanity-scrub: start setup 04:37:17 (1789115837) === [ 5711.884710] LustreError: 173499:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5711.895759] LustreError: 173499:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5711.907301] LustreError: 173499:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 15, retries 0, failed: rc = -5 [ 5712.260894] Lustre: server umount lustre-MDT0000 complete [ 5743.855221] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_hostid [ 5751.662178] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 5800.333205] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing load_modules_local [ 5812.643225] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5812.872969] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5812.915663] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5813.008843] Lustre: lustre-MDT0000: new disk, initializing [ 5813.117967] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5817.227085] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5831.164315] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5831.433851] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5831.442019] Lustre: Skipped 1 previous similar message [ 5831.528311] Lustre: lustre-MDT0001: new disk, initializing [ 5831.638325] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5831.648986] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5836.028103] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5841.095057] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5851.903345] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5852.205966] Lustre: lustre-OST0000: new disk, initializing [ 5852.209860] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5852.217077] Lustre: 180722:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5853.536494] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5853.559987] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5853.667038] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5859.926742] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5874.499314] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5874.606938] Lustre: lustre-OST0001: new disk, initializing [ 5874.610140] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5874.614634] Lustre: 181730:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5876.575143] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5876.587670] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5876.633767] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5880.996125] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5890.124123] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5893.433591] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5898.819447] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 04:40:26 (1789116026) === [ 5900.536424] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 5535 sec ========= 04:40:28 (1789116028) [ 5901.952844] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 04:40:29 (1789116029) === [ 5905.116527] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 04:40:33 (1789116033) === [ 5912.549979] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5912.558374] Lustre: Skipped 5 previous similar messages [ 5915.068770] Lustre: server umount lustre-MDT0000 complete [ 5917.669542] LustreError: 182570: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. [ 5917.688044] LustreError: 182570:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 84 previous similar messages [ 5923.205996] LustreError: 178809:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789116052 with bad export cookie 705936976148802732 [ 5923.208820] LustreError: MGC192.168.204.113@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5923.219168] LustreError: 178809:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 5923.238217] LustreError: Skipped 4 previous similar messages [ 5923.497591] Lustre: server umount lustre-MDT0001 complete [ 5943.668562] Lustre: server umount lustre-OST0000 complete [ 5944.799193] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789116057/real 1789116057] req@ffff8e20cbb69180 x1876018489728000/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789116073 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5944.829322] Lustre: 16404:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 16 previous similar messages [ 5954.269456] Lustre: server umount lustre-OST0001 complete [ 5977.278797] Lustre: DEBUG MARKER: oleg413-server.virtnet: executing unload_modules_local [ 5980.259863] Key type lgssc unregistered [ 5980.519347] LNet: 185107:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5980.529833] LNetError: 185107:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5981.544451] LNet: Removed LNI 192.168.204.113@tcp [ 5982.411982] Key type .llcrypt unregistered [ 5982.416789] Key type ._llcrypt unregistered