[ 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 819313954 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.001012] APIC: Switch to symmetric I/O mode setup [ 0.002346] x2apic enabled [ 0.003021] Switched APIC routing to physical x2apic. [ 0.004000] kvm-guest: setup PV IPIs [ 0.009000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009023] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010000] pid_max: default: 32768 minimum: 301 [ 0.010000] LSM: Security Framework initializing [ 0.010000] Yama: becoming mindful. [ 0.010000] SELinux: Initializing. [ 0.011102] *** VALIDATE selinux *** [ 0.022285] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027556] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029150] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030131] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031112] *** VALIDATE tmpfs *** [ 0.032665] *** VALIDATE proc *** [ 0.033284] *** VALIDATE cgroup *** [ 0.034069] *** VALIDATE cgroup2 *** [ 0.036317] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037157] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039000] Spectre V2 : User space: Vulnerable [ 0.039000] Speculative Store Bypass: Vulnerable [ 0.039689] debug: unmapping init [mem 0xffffffff8de59000-0xffffffff8de60fff] [ 0.040000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.041000] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.042026] ... version: 2 [ 0.043112] ... bit width: 48 [ 0.044017] ... generic registers: 4 [ 0.045093] ... value mask: 0000ffffffffffff [ 0.046018] ... max period: 00007fffffffffff [ 0.047020] ... fixed-purpose events: 3 [ 0.048018] ... event mask: 000000070000000f [ 0.050089] rcu: Hierarchical SRCU implementation. [ 0.053486] smp: Bringing up secondary CPUs ... [ 0.055705] x86: Booting SMP configuration: [ 0.056042] .... node #0, CPUs: #1 #2 #3 [ 0.071141] smp: Brought up 1 node, 4 CPUs [ 0.073014] smpboot: Max logical packages: 1 [ 0.074015] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.140000] node 0 deferred pages initialised in 65ms [ 0.154016] devtmpfs: initialized [ 0.155359] x86/mm: Memory block size: 128MB [ 0.158000] gcov: version magic: 0x41383552 [ 0.161148] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.162072] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.166405] pinctrl core: initialized pinctrl subsystem [ 0.171584] [ 0.174010] ************************************************************* [ 0.181015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.187015] ** ** [ 0.194022] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.201014] ** ** [ 0.206014] ** This means that this kernel is built to expose internal ** [ 0.208013] ** IOMMU data structures, which may compromise security on ** [ 0.213026] ** your system. ** [ 0.219015] ** ** [ 0.226016] ** If you see this message and you are not debugging the ** [ 0.228014] ** kernel, report this immediately to your vendor! ** [ 0.232101] ** ** [ 0.234011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.240013] ************************************************************* [ 0.250266] NET: Registered protocol family 16 [ 0.256346] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.262086] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.267071] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.272011] cpuidle: using governor menu [ 0.273458] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.279138] PCI: Using configuration type 1 for base access [ 0.283238] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.303353] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.305083] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.315120] cryptd: max_cpu_qlen set to 1000 [ 0.318271] ACPI: Added _OSI(Module Device) [ 0.319036] ACPI: Added _OSI(Processor Device) [ 0.320000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.322013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.334663] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.365575] ACPI: Interpreter enabled [ 0.366075] ACPI: PM: (supports S0 S3 S4 S5) [ 0.367347] ACPI: Using IOAPIC for interrupt routing [ 0.368136] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.376079] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.394932] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.395054] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.402025] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.406466] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.418157] acpiphp: Slot [2] registered [ 0.421297] acpiphp: Slot [5] registered [ 0.423219] acpiphp: Slot [6] registered [ 0.425095] acpiphp: Slot [7] registered [ 0.426088] acpiphp: Slot [8] registered [ 0.431156] acpiphp: Slot [9] registered [ 0.432105] acpiphp: Slot [10] registered [ 0.437035] acpiphp: Slot [3] registered [ 0.438144] acpiphp: Slot [4] registered [ 0.439110] acpiphp: Slot [11] registered [ 0.444134] acpiphp: Slot [12] registered [ 0.446110] acpiphp: Slot [13] registered [ 0.454181] acpiphp: Slot [14] registered [ 0.455086] acpiphp: Slot [15] registered [ 0.462167] acpiphp: Slot [16] registered [ 0.467134] acpiphp: Slot [17] registered [ 0.473139] acpiphp: Slot [18] registered [ 0.476131] acpiphp: Slot [19] registered [ 0.477000] acpiphp: Slot [20] registered [ 0.477000] acpiphp: Slot [21] registered [ 0.483343] acpiphp: Slot [22] registered [ 0.488130] acpiphp: Slot [23] registered [ 0.495850] acpiphp: Slot [24] registered [ 0.500010] acpiphp: Slot [25] registered [ 0.503125] acpiphp: Slot [26] registered [ 0.506142] acpiphp: Slot [27] registered [ 0.515180] acpiphp: Slot [28] registered [ 0.518127] acpiphp: Slot [29] registered [ 0.526021] acpiphp: Slot [30] registered [ 0.532388] acpiphp: Slot [31] registered [ 0.536154] PCI host bridge to bus 0000:00 [ 0.537029] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.544034] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.551030] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.557022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.565025] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.576040] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.579175] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.584945] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.590617] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.627015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.638067] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.639029] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.641017] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.647028] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.652084] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.657788] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.664052] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.669076] pci 0000:00:01.3: quirk_piix4_acpi+0x0/0x1e0 took 10742 usecs [ 0.680574] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.685014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.716016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.728013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.743465] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.763020] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.782014] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.822025] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.846660] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.859017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.870028] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.907115] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.926000] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.946017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.963017] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 1.009015] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 1.029567] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 1.045016] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 1.054013] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 1.092020] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 1.109979] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 1.123017] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 1.139016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 1.180033] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 1.201254] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 1.210494] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 1.222029] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 1.264018] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 1.285847] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 1.287362] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 1.290367] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 1.292697] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 1.306231] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 1.317125] iommu: Default domain type: Passthrough [ 1.318846] SCSI subsystem initialized [ 1.319252] ACPI: bus type USB registered [ 1.322127] usbcore: registered new interface driver usbfs [ 1.327206] usbcore: registered new interface driver hub [ 1.331095] usbcore: registered new device driver usb [ 1.336188] pps_core: LinuxPPS API ver. 1 registered [ 1.338013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 1.343058] PTP clock support registered [ 1.347034] EDAC MC: Ver: 3.0.0 [ 1.350168] PCI: Using ACPI for IRQ routing [ 1.351000] NetLabel: Initializing [ 1.352011] NetLabel: domain hash size = 128 [ 1.354021] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.355076] NetLabel: unlabeled traffic allowed by default [ 1.358707] vgaarb: loaded [ 1.362961] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.367013] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.373310] clocksource: Switched to clocksource kvm-clock [ 1.541474] VFS: Disk quotas dquot_6.6.0 [ 1.543121] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.547272] *** VALIDATE ramfs *** [ 1.552668] *** VALIDATE hugetlbfs *** [ 1.558388] pnp: PnP ACPI init [ 1.563092] pnp: PnP ACPI: found 6 devices [ 1.595342] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.598248] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.600418] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.602323] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.604776] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.607546] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.610113] NET: Registered protocol family 2 [ 1.616183] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.629459] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.639295] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.646133] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.653864] TCP: Hash tables configured (established 65536 bind 65536) [ 1.658800] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.672558] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.682617] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.690615] NET: Registered protocol family 1 [ 1.703049] RPC: Registered named UNIX socket transport module. [ 1.708110] RPC: Registered udp transport module. [ 1.715411] RPC: Registered tcp transport module. [ 1.725572] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.732663] NET: Registered protocol family 44 [ 1.734253] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.739804] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.745423] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.751877] PCI: CLS 0 bytes, default 64 [ 1.758192] Unpacking initramfs... [ 4.996891] debug: unmapping init [mem 0xffff94787cc54000-0xffff94787ffbffff] [ 5.020871] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 5.025936] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 5.032244] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 9.679516] Initialise system trusted keyrings [ 9.681285] Key type blacklist registered [ 9.696593] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 9.739310] zbud: loaded [ 9.748834] *** VALIDATE nfs *** [ 9.755462] *** VALIDATE nfs4 *** [ 9.765116] pstore: using deflate compression [ 9.779752] Platform Keyring initialized [ 10.570897] NET: Registered protocol family 38 [ 10.572687] Key type asymmetric registered [ 10.574169] Asymmetric key parser 'x509' registered [ 10.587527] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 10.591843] io scheduler mq-deadline registered [ 10.595750] io scheduler kyber registered [ 10.597590] io scheduler bfq registered [ 10.602938] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 10.605710] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 10.611823] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 10.618238] ACPI: Power Button [PWRF] [ 10.628492] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 10.641073] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 10.666810] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 10.681507] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 10.739510] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 10.824758] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 10.944360] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 10.981802] Non-volatile memory driver v1.3 [ 10.985740] Linux agpgart interface v0.103 [ 11.148573] virtio_blk virtio1: [vda] 134776 512-byte logical blocks (69.0 MB/65.8 MiB) [ 11.156087] vda: detected capacity change from 0 to 69005312 [ 11.238480] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 11.249579] vdb: detected capacity change from 0 to 1073741824 [ 11.295825] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 11.311775] vdc: detected capacity change from 0 to 2621440000 [ 11.352343] hrtimer: interrupt took 2514944 ns [ 11.373358] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 11.378671] vdd: detected capacity change from 0 to 2621440000 [ 11.419760] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 11.425939] vde: detected capacity change from 0 to 4294967296 [ 11.478625] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 11.483238] vdf: detected capacity change from 0 to 4294967296 [ 11.506576] libphy: Fixed MDIO Bus: probed [ 11.525821] usbcore: registered new interface driver usbserial_generic [ 11.529015] usbserial: USB Serial support registered for generic [ 11.531572] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 11.564966] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 11.567023] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 11.587964] mousedev: PS/2 mouse device common for all mice [ 11.602387] rtc_cmos 00:05: RTC can wake from S4 [ 11.611272] rtc_cmos 00:05: registered as rtc0 [ 11.611470] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 11.612656] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 11.612692] intel_pstate: CPU model not supported [ 11.614805] hid: raw HID events driver (C) Jiri Kosina [ 11.650962] usbcore: registered new interface driver usbhid [ 11.654256] usbhid: USB HID core driver [ 11.655798] drop_monitor: Initializing network drop monitor service [ 11.671987] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 11.677916] Initializing XFRM netlink socket [ 11.686531] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 11.684358] NET: Registered protocol family 10 [ 11.698264] Segment Routing with IPv6 [ 11.702925] NET: Registered protocol family 17 [ 11.710811] mpls_gso: MPLS GSO support [ 11.724872] RAS: Correctable Errors collector initialized. [ 11.727769] AVX version of gcm_enc/dec engaged. [ 11.731393] AES CTR mode by8 optimization enabled [ 12.138574] sched_clock: Marking stable (12138554478, 0)->(14185515359, -2046960881) [ 12.153627] registered taskstats version 1 [ 12.160381] Loading compiled-in X.509 certificates [ 12.165181] zswap: loaded using pool lzo/zbud [ 12.218574] Key type big_key registered [ 12.235375] Key type encrypted registered [ 12.237739] ima: No TPM chip found, activating TPM-bypass! [ 12.240478] ima: Allocated hash algorithm: sha1 [ 12.243068] ima: No architecture policies found [ 12.245486] evm: Initialising EVM extended attributes: [ 12.247651] evm: security.selinux [ 12.249439] evm: security.ima [ 12.250641] evm: security.capability [ 12.252183] evm: HMAC attrs: 0x1 [ 12.283418] rtc_cmos 00:05: setting system clock to 2026-05-25 07:08:50 UTC (1779692930) [ 12.296789] debug: unmapping init [mem 0xffffffff8ee03000-0xffffffff8effffff] [ 12.353108] debug: unmapping init [mem 0xffffffff8db82000-0xffffffff8de58fff] [ 12.377014] Write protecting the kernel read-only data: 28672k [ 12.399674] debug: unmapping init [mem 0xffffffff8c203000-0xffffffff8c3fffff] [ 12.412699] debug: unmapping init [mem 0xffffffff8cb14000-0xffffffff8cbfffff] [ 12.576904] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.611115] systemd[1]: Detected virtualization kvm. [ 12.613067] systemd[1]: Detected architecture x86-64. [ 12.625461] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 12.749283] systemd[1]: No hostname configured. [ 12.755568] systemd[1]: Set hostname to . [ 12.770629] random: systemd: uninitialized urandom read (16 bytes read) [ 12.779619] systemd[1]: Initializing machine ID from random generator. [ 13.251238] random: systemd: uninitialized urandom read (16 bytes read) [ 13.260197] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 13.273825] random: systemd: uninitialized urandom read (16 bytes read) [ 13.276743] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 13.283168] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK ] Reached target Timers. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Reached target Initrd Root Device. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Reached target Swap. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 16.012441] device-mapper: uevent: version 1.0.3 [ 16.015528] 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. [ 18.524616] virtio_net virtio0 ens2: renamed from eth0 [ 18.872144] random: fast init done [ 19.240896] scsi host0: ata_piix [ 19.497835] scsi host1: ata_piix [ 19.517626] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 19.540189] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 24.808183] random: crng init done [ 24.809536] random: 7 urandom warning(s) missed due to ratelimiting [ 28.317943] dracut-initqueue[589]: 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... [ 30.221451] 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... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ 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 Cleaning Up and Shutting Down Daemons. [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 34.169957] printk: systemd: 26 output lines suppressed due to ratelimiting [ 35.445778] SELinux: Disabled at runtime. [ 35.637572] 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) [ 35.655538] systemd[1]: Detected virtualization kvm. [ 35.663203] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 38.256527] systemd[1]: initrd-switch-root.service: Succeeded. [ 38.265129] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 38.316599] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 38.331831] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 38.348567] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 38.388236] systemd[1]: Starting Journal Service... Starting Journal Service... [ 38.428081] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-serial\x2dgetty.slice. Mounting Kernel Debug File System... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Created slice system-getty.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on Process Core Dump Socket. Starting Create list of required st…ce nodes for the current kernel... Mounting Huge Pages File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on initctl Compatibility Named Pipe. Starting Apply Kernel Variables... Starting Remount Root and Kernel File Systems... [ OK ] Reached target RPC Port Mapper. [ OK ] Reached target Paths. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ 39.081298] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 40.384434] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 41.843049] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 41.887298] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 42.684251] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 42.890524] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (9s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ ***] A start job is running for Configur…only root support (11s / no limit) [ **] A start job is running for Configur…only root support (11s / no limit) [ *[ 50.209927] Key type dns_resolver registered ] A start job is running for Configur…only root support (12s / no limit) [ **] A start job is running for Configur…only root support (12s / no limit) [ ***] A start job is running for Configur…only root support (13s / no limit)[ 51.337630] NFS: Registering the id_resolver key type [ 51.340674] Key type id_resolver registered [ 51.342953] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (13s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... 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 ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg460-server login: [ 124.393919] libcfs: loading out-of-tree module taints kernel. [ 124.445486] Key type ._llcrypt registered [ 124.449705] Key type .llcrypt registered [ 124.594674] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_hostid [ 142.519407] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 144.128663] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 144.164945] alg: No test for adler32 (adler32-zlib) [ 145.614189] Lustre: Lustre: Build Version: 2.17.53_24_gacb3840 [ 146.848879] LNet: Added LNI 192.168.204.160@tcp [8/256/0/180] [ 148.695223] Key type lgssc registered [ 150.315235] Lustre: Echo OBD driver; http://www.lustre.org/ [ 167.915106] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 209.887319] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 222.015345] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 222.043312] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 223.268490] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 223.307226] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 223.403386] Lustre: lustre-MDT0000: new disk, initializing [ 223.499957] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 223.526169] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 227.514699] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 240.628462] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 240.730705] Lustre: 6507: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 [ 240.755780] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 240.760488] Lustre: Skipped 1 previous similar message [ 240.840996] Lustre: lustre-MDT0001: new disk, initializing [ 240.927593] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 240.968225] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 240.979284] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 245.039812] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 249.554462] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 258.229606] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 258.468786] Lustre: lustre-OST0000: new disk, initializing [ 258.471898] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 258.475954] Lustre: 8410:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 258.544489] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 263.905531] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 265.754401] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 265.763803] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 265.834916] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 278.152820] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 278.346436] Lustre: lustre-OST0001: new disk, initializing [ 278.354246] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 278.364077] Lustre: 9466:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 278.472804] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 284.790427] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 286.244965] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 286.263482] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 286.339566] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 297.064915] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 303.991231] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 311.102159] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing check_logdir /tmp/testlogs/ [ 315.824761] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing yml_node [ 321.510981] Lustre: DEBUG MARKER: Client: 2.17.53.24 [ 324.119814] Lustre: DEBUG MARKER: MDS: 2.17.53.24 [ 326.921853] Lustre: DEBUG MARKER: OSS: 2.17.53.24 [ 328.860751] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Mon May 25 03:14:04 EDT 2026 [ 344.840359] Lustre: DEBUG MARKER: excepting tests: [ 355.112630] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 362.985412] 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 [ 362.988448] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 362.994598] Lustre: Skipped 1 previous similar message [ 368.107872] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 368.124727] Lustre: Skipped 6 previous similar messages [ 368.857373] Lustre: server umount lustre-MDT0000 complete [ 376.948585] LustreError: 9465:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779693295 with bad export cookie 5324809019698237011 [ 376.949145] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 376.970654] LustreError: 9465:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 377.304723] Lustre: server umount lustre-MDT0001 complete [ 394.527185] Lustre: 3659:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693296/real 1779693296] req@ffff9477c6f84380 x1866143435423744/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693312 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 394.558094] 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 [ 394.573890] Lustre: Skipped 2 previous similar messages [ 396.028709] Lustre: server umount lustre-OST0000 complete [ 397.280390] Lustre: 3657:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693299/real 1779693299] req@ffff9478c12aca80 x1866143435424000/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693315 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 398.815562] Lustre: 3660:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693301/real 1779693301] req@ffff9478ffbf1180 x1866143435424256/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693317 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 404.447293] Lustre: 3657:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693306/real 1779693306] req@ffff9477c743aa00 x1866143435424640/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693322 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 405.276921] Lustre: server umount lustre-OST0001 complete [ 423.487442] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing unload_modules_local [ 427.092612] Key type lgssc unregistered [ 427.549577] LNet: 14704:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 427.563249] LNetError: 14704:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 427.596961] LNet: Removed LNI 192.168.204.160@tcp [ 428.618168] Key type .llcrypt unregistered [ 428.619942] Key type ._llcrypt unregistered [ 453.711249] Key type ._llcrypt registered [ 453.713470] Key type .llcrypt registered [ 453.795518] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_hostid [ 467.688620] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 468.944258] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 468.993685] alg: No test for adler32 (adler32-zlib) [ 470.129518] Lustre: Lustre: Build Version: 2.17.53_24_gacb3840 [ 470.398750] LNet: Added LNI 192.168.204.160@tcp [8/256/0/180] [ 472.103682] Key type lgssc registered [ 473.339748] Lustre: Echo OBD driver; http://www.lustre.org/ [ 524.412385] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 537.566209] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 537.615412] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 538.814202] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 538.843501] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 538.898241] Lustre: lustre-MDT0000: new disk, initializing [ 538.976680] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 539.003981] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 543.281359] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 556.001895] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 556.093315] Lustre: 19115: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 [ 556.120372] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 556.124988] Lustre: Skipped 1 previous similar message [ 556.220802] Lustre: lustre-MDT0001: new disk, initializing [ 556.297274] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 556.324695] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 556.340827] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 561.220379] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 566.187562] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 574.832135] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 575.042444] Lustre: lustre-OST0000: new disk, initializing [ 575.046562] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 575.052658] Lustre: 21021:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 575.126133] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 580.709642] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 583.720410] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 583.728844] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 583.770825] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 593.068130] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 593.179730] Lustre: lustre-OST0001: new disk, initializing [ 593.183178] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 593.192776] Lustre: 22028:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 593.261660] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 599.021913] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 599.575234] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 599.590508] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 599.672320] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 610.378448] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 618.092167] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 624.897287] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 03:19:01 (1779693541) === [ 626.901823] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 03:19:02 (1779693542) [ 645.816459] Lustre: Failing over lustre-MDT0000 [ 646.163382] Lustre: server umount lustre-MDT0000 complete [ 648.676092] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 648.686985] 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 [ 650.158868] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779693568 with bad export cookie 2085859817973305983 [ 650.169941] Lustre: Failing over lustre-MDT0001 [ 650.174345] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 650.178182] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 650.688692] Lustre: server umount lustre-MDT0001 complete [ 659.822716] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 660.757158] LustreError: 21013: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. [ 660.776157] LustreError: 21013:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 660.846158] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 660.900829] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 665.521330] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 665.891293] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693568/real 1779693568] req@ffff9477cbc5a300 x1866143774141824/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693584 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 665.919590] 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 [ 665.937199] LustreError: 21014: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. [ 665.950241] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 665.964295] LustreError: 21014:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 671.203703] LustreError: 24031: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. [ 671.237084] LustreError: 24031:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 672.223765] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693574/real 1779693574] req@ffff9477c6ec5f80 x1866143774142336/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693590 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 672.246715] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 674.410258] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 674.803146] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 674.906349] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 674.933130] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 674.938421] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 675.874604] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693578/real 1779693578] req@ffff9477c6ec4e00 x1866143774142976/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693594 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 675.924560] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 679.905711] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 679.911625] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 679.924169] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 679.929567] Lustre: Skipped 1 previous similar message [ 679.988908] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 680.038300] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 680.038306] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 692.994706] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 03:20:09 (1779693609) [ 715.514227] Lustre: Failing over lustre-MDT0000 [ 715.752733] 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 [ 715.755740] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 715.771307] Lustre: Skipped 5 previous similar messages [ 715.775148] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 715.810812] Lustre: Skipped 3 previous similar messages [ 717.920163] Lustre: server umount lustre-MDT0000 complete [ 720.867414] LustreError: 24030: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. [ 720.894485] LustreError: 24030:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 721.923573] Lustre: Failing over lustre-MDT0001 [ 721.927910] LustreError: 25513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779693640 with bad export cookie 2085859817973322293 [ 721.928249] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 721.980569] LustreError: 25513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 722.310602] Lustre: server umount lustre-MDT0001 complete [ 730.422665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 732.425182] LustreError: 21013: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. [ 732.518168] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 732.551694] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 737.169898] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 737.776215] 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 [ 737.798565] Lustre: Skipped 2 previous similar messages [ 741.857410] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693644/real 1779693644] req@ffff9477cbd16d80 x1866143774260480/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693660 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 741.884510] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 742.884713] LustreError: 26383: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. [ 742.904099] LustreError: 26383:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 745.785778] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 745.951335] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693648/real 1779693648] req@ffff9477c6d0bb80 x1866143774260992/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693664 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 745.953284] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 745.968787] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 745.976793] Lustre: Skipped 2 previous similar messages [ 746.115230] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 746.287363] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 746.294293] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 750.513591] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 751.597902] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 751.611133] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 751.629936] Lustre: Skipped 1 previous similar message [ 751.698089] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 751.792100] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 751.793457] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 755.197240] Lustre: *** cfs_fail_loc=193, val=0*** [ 761.749466] Lustre: Failing over lustre-MDT0000 [ 761.824563] 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 [ 761.831613] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 761.843271] Lustre: Skipped 3 previous similar messages [ 761.863197] Lustre: Skipped 3 previous similar messages [ 762.486868] Lustre: server umount lustre-MDT0000 complete [ 766.958633] LustreError: 24996: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. [ 766.976265] LustreError: 24996:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 772.578218] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 772.754411] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 773.133972] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 773.151384] Lustre: Skipped 1 previous similar message [ 773.218548] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 777.404923] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 778.215282] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 778.218659] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 778.263205] Lustre: Skipped 2 previous similar messages [ 778.311316] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 778.379428] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:161) [ 778.382198] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:161) [ 788.295552] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 03:21:44 (1779693704) [ 801.066669] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 821.817382] Lustre: 30198:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 845.183972] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 849.845426] Lustre: 31333:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 864.857692] Lustre: *** cfs_fail_loc=198, val=0*** [ 876.335647] Lustre: Failing over lustre-MDT0000 [ 876.874812] Lustre: server umount lustre-MDT0000 complete [ 880.609445] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 880.611879] 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 [ 880.616561] LustreError: 26384: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. [ 880.616576] LustreError: 26384:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 880.674581] Lustre: Skipped 2 previous similar messages [ 881.424623] LustreError: 25513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779693799 with bad export cookie 2085859817973351364 [ 881.426425] Lustre: Failing over lustre-MDT0001 [ 881.441306] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 881.818776] Lustre: server umount lustre-MDT0001 complete [ 887.154453] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 892.014430] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 901.087120] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693803/real 1779693803] req@ffff9478e5f72300 x1866143774438912/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693819 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 901.091873] 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 [ 901.121795] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 901.160334] Lustre: Skipped 2 previous similar messages [ 901.227389] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 906.631487] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 906.690557] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 911.342965] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 919.446801] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 919.677367] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 919.815923] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 919.821659] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 920.806925] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 920.817447] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 920.839971] Lustre: Skipped 3 previous similar messages [ 920.933135] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 920.991854] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 921.002540] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 924.863135] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 936.051862] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 03:24:12 (1779693852) [ 958.081724] Lustre: Failing over lustre-MDT0000 [ 958.395847] Lustre: server umount lustre-MDT0000 complete [ 962.015818] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 962.016556] 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 [ 962.017344] LustreError: 34291: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. [ 962.017353] LustreError: 34291:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 962.065932] Lustre: Skipped 2 previous similar messages [ 962.282349] Lustre: Failing over lustre-MDT0001 [ 962.283827] LustreError: 19107:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779693880 with bad export cookie 2085859817973378874 [ 962.284404] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 962.320594] LustreError: 19107:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 962.618044] Lustre: server umount lustre-MDT0001 complete [ 967.381448] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 972.125613] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 980.393165] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 980.521850] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 983.391127] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779693885/real 1779693885] req@ffff9478eeb37800 x1866143774557568/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779693901 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 983.416741] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 987.619974] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fd90dafd [ 987.627359] Lustre: MGC192.168.204.160@tcp: Connection restored to 0@lo (at 0@lo) [ 987.636996] Lustre: Skipped 4 previous similar messages [ 988.065890] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 992.630789] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1001.419611] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1001.449964] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1001.649415] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1001.762695] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:233 to 0x2c0000400:257) [ 1001.766731] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:234 to 0x280000400:257) [ 1002.724348] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1002.768254] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1002.833683] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 1002.834702] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 1006.486908] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1031.056666] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 1048.039261] Lustre: 38558:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1067.563837] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1070.774551] Lustre: 39693:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1095.519871] Lustre: Failing over lustre-MDT0000 [ 1097.777697] Lustre: server umount lustre-MDT0000 complete [ 1100.256180] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1100.261119] 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 [ 1100.270285] LustreError: 24996: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. [ 1100.275107] Lustre: Skipped 6 previous similar messages [ 1100.284903] LustreError: 24996:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 1102.003895] Lustre: Failing over lustre-MDT0001 [ 1102.005812] LustreError: 21020:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694020 with bad export cookie 2085859817973406461 [ 1102.012682] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1102.044272] LustreError: 21020:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1102.338911] Lustre: server umount lustre-MDT0001 complete [ 1107.053862] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1114.685804] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1121.695144] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779694023/real 1779694023] req@ffff9478e5938e00 x1866143774700416/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779694039 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1121.731735] Lustre: 16286:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 1126.564548] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1126.611351] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 1127.333813] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1127.338584] Lustre: Skipped 3 previous similar messages [ 1127.379030] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1131.583623] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1140.731489] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1140.741515] Lustre: Skipped 5 previous similar messages [ 1141.062392] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1141.122703] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 1141.579887] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1141.588217] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 1145.946252] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1146.855426] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1146.889636] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1146.955353] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 1146.965039] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 1170.882078] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 1191.579293] Lustre: 44353:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1217.574669] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1221.500603] Lustre: 45489:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1246.338653] Lustre: Failing over lustre-MDT0000 [ 1246.686343] Lustre: server umount lustre-MDT0000 complete [ 1249.254465] 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 [ 1249.269685] Lustre: Skipped 4 previous similar messages [ 1249.274556] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1249.284676] LustreError: Skipped 1 previous similar message [ 1250.848925] LustreError: 19106:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694169 with bad export cookie 2085859817973433712 [ 1250.849911] Lustre: Failing over lustre-MDT0001 [ 1250.852630] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1250.864715] LustreError: 19106:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1251.368708] Lustre: server umount lustre-MDT0001 complete [ 1256.370491] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1263.472710] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1270.751087] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779694172/real 1779694172] req@ffff9477cd30a300 x1866143774845440/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779694188 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1270.780345] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 1275.159255] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1275.209109] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 1275.935942] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9478fede7800 x1866143774847872/t0(0) o250->MGC192.168.204.160@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 [ 1276.467411] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1281.192680] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1289.699825] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1289.705590] Lustre: Skipped 4 previous similar messages [ 1290.010917] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1290.082368] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 1290.432050] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 1290.433367] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:361 to 0x2c0000400:385) [ 1294.745769] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1295.842530] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1295.886852] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1295.965055] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:394 to 0x2c0000401:417) [ 1295.966749] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:393 to 0x280000401:417) [ 1311.846344] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 03:30:27 (1779694227) [ 1326.943381] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 1344.972052] Lustre: 50146:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1369.302772] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1397.549030] Lustre: Failing over lustre-MDT0000 [ 1397.921245] Lustre: server umount lustre-MDT0000 complete [ 1398.260993] LustreError: 21013: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. [ 1398.282302] LustreError: 21013:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 30 previous similar messages [ 1402.059606] Lustre: Failing over lustre-MDT0001 [ 1402.061810] LustreError: 19106:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694320 with bad export cookie 2085859817973460963 [ 1402.062358] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1402.096448] LustreError: 19106:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1402.406223] Lustre: server umount lustre-MDT0001 complete [ 1408.865425] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1419.609321] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1419.745059] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779694321/real 1779694321] req@ffff9478e5dbea00 x1866143774992512/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779694337 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1419.777833] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1427.960187] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1439.366035] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1451.106987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1451.122971] Lustre: lustre-MDT0000: reset Object Index mappings [ 1472.400810] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1472.413166] Lustre: Skipped 3 previous similar messages [ 1472.437399] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1476.452740] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1484.418388] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1484.433546] Lustre: lustre-MDT0001: reset Object Index mappings [ 1484.775578] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 1484.780808] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 1487.856350] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1487.862182] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1487.876875] Lustre: Skipped 4 previous similar messages [ 1487.920484] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1487.970076] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 1487.975507] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 1489.717165] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1501.022989] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 03:33:37 (1779694417) [ 1526.458848] Lustre: Failing over lustre-MDT0000 [ 1526.932073] Lustre: server umount lustre-MDT0000 complete [ 1528.801111] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1528.805521] LustreError: Skipped 3 previous similar messages [ 1528.810474] 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 [ 1528.830409] Lustre: Skipped 9 previous similar messages [ 1530.873320] LustreError: 25513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694449 with bad export cookie 2085859817973488214 [ 1530.875909] Lustre: Failing over lustre-MDT0001 [ 1530.880515] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1531.321675] Lustre: server umount lustre-MDT0001 complete [ 1536.936871] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1548.848422] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1557.669341] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1568.875638] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1581.434891] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1581.459604] Lustre: lustre-MDT0000: reset Object Index mappings [ 1601.503747] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9478c6065f80 x1866143775113984/t0(0) o250->MGC192.168.204.160@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 [ 1602.210696] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1607.656969] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1618.342152] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1618.366762] Lustre: lustre-MDT0001: reset Object Index mappings [ 1618.854313] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:489 to 0x280000400:513) [ 1618.872465] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 1620.844314] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1620.895287] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1620.945832] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:521 to 0x280000401:545) [ 1620.953220] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:522 to 0x2c0000401:545) [ 1623.290056] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1630.332332] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32009: rc = 0 [ 1631.523827] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/64040 with flags 0x52: rc = 0 [ 1653.698223] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 03:36:09 (1779694569) [ 1676.770946] Lustre: Failing over lustre-MDT0000 [ 1677.054756] Lustre: server umount lustre-MDT0000 complete [ 1681.319843] Lustre: Failing over lustre-MDT0001 [ 1681.323812] LustreError: 34300:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694599 with bad export cookie 2085859817973515479 [ 1681.324950] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1681.337698] LustreError: 34300:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 1681.894568] Lustre: server umount lustre-MDT0001 complete [ 1688.099744] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1698.673906] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1699.812900] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779694601/real 1779694601] req@ffff9478d0512300 x1866143775240704/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779694617 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1699.855764] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 20 previous similar messages [ 1707.798815] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1717.779273] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1731.803119] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1731.841154] Lustre: lustre-MDT0000: reset Object Index mappings [ 1751.075844] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fd92f0cb [ 1751.089395] Lustre: MGC192.168.204.160@tcp: Connection restored to 0@lo (at 0@lo) [ 1751.106697] Lustre: Skipped 9 previous similar messages [ 1751.669860] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1757.920863] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1769.836513] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1769.865152] Lustre: lustre-MDT0001: reset Object Index mappings [ 1770.018089] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 1770.022789] Lustre: Skipped 2 previous similar messages [ 1770.265900] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:554 to 0x280000400:577) [ 1770.285540] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:553 to 0x2c0000400:577) [ 1775.154077] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1775.593125] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1775.651831] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1775.718551] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:586 to 0x280000401:609) [ 1775.720625] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:585 to 0x2c0000401:609) [ 1784.111955] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32026: rc = 0 [ 1787.392412] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 1909.748462] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 03:40:25 (1779694825) [ 1948.067713] Lustre: Failing over lustre-MDT0000 [ 1948.443944] Lustre: server umount lustre-MDT0000 complete [ 1949.674226] LustreError: 63976: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. [ 1949.699722] LustreError: 63976:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 25 previous similar messages [ 1953.027269] Lustre: Failing over lustre-MDT0001 [ 1953.029666] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779694871 with bad export cookie 2085859817973543115 [ 1953.031386] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1953.079646] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1953.513302] Lustre: server umount lustre-MDT0001 complete [ 1959.947127] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1970.530063] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1981.485163] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1994.777340] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2007.840569] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2007.860565] Lustre: lustre-MDT0000: reset Object Index mappings [ 2023.964653] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2023.967806] Lustre: Skipped 5 previous similar messages [ 2024.027277] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2029.289925] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2040.454417] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2040.487497] Lustre: lustre-MDT0001: reset Object Index mappings [ 2040.832421] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2040.847946] LustreError: Skipped 4 previous similar messages [ 2041.000702] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 2041.007176] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:617 to 0x280000400:641) [ 2041.956047] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2042.065299] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2042.136405] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:650 to 0x280000401:673) [ 2042.137932] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:649 to 0x2c0000401:673) [ 2046.774956] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2056.219679] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/96004: rc = 0 [ 2059.561906] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 2148.662736] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 03:44:24 (1779695064) [ 2166.536650] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2166.538717] Lustre: Skipped 1 previous similar message [ 2167.038418] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2167.040556] Lustre: Skipped 53 previous similar messages [ 2168.044544] Lustre: *** cfs_fail_loc=19b, val=0*** [ 2168.048587] Lustre: Skipped 217 previous similar messages [ 2185.768510] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 03:45:01 (1779695101) [ 2190.951169] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 2190.956580] Lustre: Skipped 183 previous similar messages [ 2205.173960] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 03:45:21 (1779695121) [ 2221.536679] 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 [ 2221.539846] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2221.556448] Lustre: Skipped 20 previous similar messages [ 2221.584887] Lustre: Skipped 3 previous similar messages [ 2226.656293] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2226.665457] Lustre: Skipped 3 previous similar messages [ 2231.776677] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2231.785050] Lustre: Skipped 3 previous similar messages [ 2234.336376] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2234.590101] Lustre: server umount lustre-MDT0000 complete [ 2238.736459] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779695156 with bad export cookie 2085859817973587243 [ 2238.755444] LustreError: 19108:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2242.017683] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2253.280274] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2253.283415] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 4. Is it stuck? [ 2253.286530] Lustre: Skipped 6 previous similar messages [ 2253.581364] Lustre: server umount lustre-MDT0001 complete [ 2264.290796] Lustre: server umount lustre-OST0000 complete [ 2275.479215] Lustre: server umount lustre-OST0001 complete [ 2283.429489] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_hostid [ 2291.769482] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 2334.614785] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 2344.323069] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2344.617397] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2344.668523] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2344.834727] Lustre: lustre-MDT0000: new disk, initializing [ 2344.920849] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2349.092632] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2360.382984] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2360.478346] Lustre: 75141: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 [ 2360.487285] Lustre: 75141:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 2360.528326] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2360.532441] Lustre: Skipped 1 previous similar message [ 2360.660654] Lustre: lustre-MDT0001: new disk, initializing [ 2360.774280] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2360.790030] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2365.486195] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2370.515803] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2378.522824] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2378.740613] Lustre: lustre-OST0000: new disk, initializing [ 2378.750955] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2378.761062] Lustre: 76740:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2380.177595] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2380.189142] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2380.244171] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2385.010317] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2396.081484] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2396.302256] Lustre: lustre-OST0001: new disk, initializing [ 2396.307693] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2396.310918] Lustre: 77593:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2397.504737] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2397.515415] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2397.673199] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2403.678512] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2413.132640] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2416.463670] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2439.568406] Lustre: Failing over lustre-MDT0000 [ 2439.872857] Lustre: server umount lustre-MDT0000 complete [ 2443.901703] Lustre: Failing over lustre-MDT0001 [ 2444.196069] Lustre: server umount lustre-MDT0001 complete [ 2450.680763] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2460.250286] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2464.991529] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779695367/real 1779695367] req@ffff9478edcce300 x1866143775752704/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779695383 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2465.029389] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 2468.179879] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2477.999387] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2490.122677] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2490.138764] Lustre: lustre-MDT0000: reset Object Index mappings [ 2519.503656] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2528.965728] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2529.410330] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 2529.423529] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 2533.854915] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2534.423353] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2534.439660] Lustre: Skipped 10 previous similar messages [ 2534.471994] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 2534.477231] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 2544.884928] Lustre: *** cfs_fail_loc=190, val=3*** [ 2544.885498] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/32004: rc = 0 [ 2545.952623] Lustre: *** cfs_fail_loc=190, val=3*** [ 2545.956602] Lustre: Skipped 1 previous similar message [ 2547.047437] Lustre: *** cfs_fail_loc=190, val=3*** [ 2548.245240] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/50 with flags 0x52: rc = 0 [ 2550.111226] Lustre: *** cfs_fail_loc=190, val=3*** [ 2550.113886] Lustre: Skipped 2 previous similar messages [ 2554.335092] Lustre: *** cfs_fail_loc=191, val=3*** [ 2554.339542] Lustre: Skipped 2 previous similar messages [ 2559.871292] Lustre: Failing over lustre-MDT0000 [ 2559.973789] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2560.263620] Lustre: server umount lustre-MDT0000 complete [ 2562.538192] LustreError: 76734: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. [ 2562.553310] LustreError: 76734:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 30 previous similar messages [ 2564.645187] Lustre: Failing over lustre-MDT0001 [ 2564.645280] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2564.668385] LustreError: Skipped 2 previous similar messages [ 2565.375850] Lustre: server umount lustre-MDT0001 complete [ 2578.936424] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2589.152722] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9477ced3ca80 x1866143775796096/t0(0) o250->MGC192.168.204.160@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 [ 2589.784436] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2589.810948] Lustre: Skipped 1 previous similar message [ 2595.839079] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2605.928862] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2606.277881] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:97) [ 2606.280667] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 2610.830279] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2611.695633] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2611.710836] Lustre: Skipped 1 previous similar message [ 2611.743373] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2611.752896] Lustre: Skipped 1 previous similar message [ 2611.790498] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 2611.793709] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 2616.786407] Lustre: Failing over lustre-MDT0000 [ 2616.801793] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2616.810639] Lustre: Skipped 3 previous similar messages [ 2619.030231] Lustre: server umount lustre-MDT0000 complete [ 2622.783995] Lustre: Failing over lustre-MDT0001 [ 2623.133830] Lustre: server umount lustre-MDT0001 complete [ 2632.268090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2632.478545] Lustre: *** cfs_fail_loc=190, val=3*** [ 2632.481324] Lustre: Skipped 1 previous similar message [ 2647.964318] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2647.972670] Lustre: Skipped 9 previous similar messages [ 2650.527291] Lustre: *** cfs_fail_loc=190, val=3*** [ 2650.532342] Lustre: Skipped 5 previous similar messages [ 2652.774520] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2661.551632] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2661.769833] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2661.774965] LustreError: Skipped 6 previous similar messages [ 2661.876910] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:129) [ 2661.893382] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 2666.596565] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2667.055815] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:129) [ 2667.057305] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 2678.236301] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/204: rc = 0 [ 2678.263665] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/50 with flags 0x52: rc = 0 [ 2689.329757] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 03:53:25 (1779695605) [ 2714.497116] Lustre: Failing over lustre-MDT0000 [ 2714.751267] Lustre: server umount lustre-MDT0000 complete [ 2718.021597] Lustre: Failing over lustre-MDT0001 [ 2718.176823] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2718.187082] Lustre: Skipped 1 previous similar message [ 2718.435302] Lustre: server umount lustre-MDT0001 complete [ 2724.000846] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2734.127287] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2742.573923] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2751.247727] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2762.634829] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2762.650017] Lustre: lustre-MDT0000: reset Object Index mappings [ 2762.652403] Lustre: Skipped 1 previous similar message [ 2763.248397] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fd96079a [ 2767.825308] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2776.961798] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2777.313422] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2777.343280] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 2781.657923] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2782.794511] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 2782.795965] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 2789.773847] Lustre: *** cfs_fail_loc=190, val=2*** [ 2789.776416] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/64001: rc = 0 [ 2789.778522] Lustre: Skipped 12 previous similar messages [ 2793.076214] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 2805.941458] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x45:0x0]/57: rc = 0 [ 2823.148313] Lustre: Failing over lustre-MDT0000 [ 2823.524612] Lustre: server umount lustre-MDT0000 complete [ 2823.653302] 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 [ 2823.676419] Lustre: Skipped 24 previous similar messages [ 2828.188298] LustreError: 87177:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779695746 with bad export cookie 2085859817973745562 [ 2828.190479] Lustre: Failing over lustre-MDT0001 [ 2828.199364] LustreError: 87177:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 2828.658911] Lustre: server umount lustre-MDT0001 complete [ 2839.900223] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2853.286089] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fd960f0a [ 2855.144135] Lustre: *** cfs_fail_loc=190, val=3*** [ 2855.146284] Lustre: Skipped 29 previous similar messages [ 2857.825482] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2866.230324] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2866.736067] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2866.741381] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 2870.806740] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2871.839539] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:225) [ 2871.841363] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:225) [ 2891.677279] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 03:56:47 (1779695807) [ 2906.672596] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 2925.793317] Lustre: 95579:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2949.912814] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2953.420808] Lustre: 96715:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2990.602898] Lustre: Failing over lustre-MDT0000 [ 2991.026807] Lustre: server umount lustre-MDT0000 complete [ 2994.739738] Lustre: Failing over lustre-MDT0001 [ 2995.020659] Lustre: server umount lustre-MDT0001 complete [ 3000.594731] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3010.392783] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3020.010624] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3034.073047] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3046.736707] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3046.769802] Lustre: lustre-MDT0000: reset Object Index mappings [ 3046.773431] Lustre: Skipped 1 previous similar message [ 3068.482590] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3076.766517] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3077.064786] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 3077.095247] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:265 to 0x2c0000400:289) [ 3080.892384] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3082.305841] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 3082.312546] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 3089.258479] Lustre: *** cfs_fail_loc=190, val=3*** [ 3089.260031] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32002: rc = 0 [ 3089.264695] Lustre: Skipped 11 previous similar messages [ 3089.300415] Lustre: Skipped 1 previous similar message [ 3092.672865] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 3115.386830] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 04:00:31 (1779696031) [ 3160.358426] Lustre: Failing over lustre-MDT0000 [ 3160.954109] Lustre: server umount lustre-MDT0000 complete [ 3164.914752] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3164.917930] Lustre: Failing over lustre-MDT0001 [ 3164.923358] LustreError: Skipped 4 previous similar messages [ 3165.403897] Lustre: server umount lustre-MDT0001 complete [ 3171.755260] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3182.665141] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3183.455193] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779696085/real 1779696085] req@ffff9477cc58a300 x1866143776290432/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779696101 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3183.482832] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 52 previous similar messages [ 3190.966904] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3200.989691] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3213.758172] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3235.746864] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fd983299 [ 3235.763268] Lustre: MGC192.168.204.160@tcp: Connection restored to 0@lo (at 0@lo) [ 3235.768233] Lustre: Skipped 31 previous similar messages [ 3236.150665] LustreError: 76734: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. [ 3236.166699] LustreError: 76734:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 55 previous similar messages [ 3236.364802] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3236.373682] Lustre: Skipped 4 previous similar messages [ 3240.555506] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3250.157816] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3250.592666] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3250.598229] Lustre: Skipped 8 previous similar messages [ 3250.639477] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:330 to 0x2c0000400:353) [ 3250.643413] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:329 to 0x280000400:353) [ 3252.654089] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3252.666345] Lustre: Skipped 4 previous similar messages [ 3252.712370] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3252.721248] Lustre: Skipped 4 previous similar messages [ 3252.797385] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 3252.799622] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 3255.114243] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3291.511717] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 04:03:27 (1779696207) [ 3303.486912] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 3318.262960] Lustre: 108168:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3338.648468] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3459.425472] Lustre: Failing over lustre-MDT0000 [ 3459.978243] Lustre: server umount lustre-MDT0000 complete [ 3462.624511] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3462.632534] LustreError: Skipped 6 previous similar messages [ 3462.639989] 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 [ 3462.654171] Lustre: Skipped 17 previous similar messages [ 3463.341734] LustreError: 75919:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779696381 with bad export cookie 2085859817973887641 [ 3463.347109] Lustre: Failing over lustre-MDT0001 [ 3463.353359] LustreError: 75919:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 3463.659028] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3463.670685] Lustre: Skipped 1 previous similar message [ 3463.988526] Lustre: server umount lustre-MDT0001 complete [ 3469.176379] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3479.362681] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3490.484930] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3502.447264] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3514.921933] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3540.390813] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3550.048031] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3550.414637] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:393 to 0x280000400:417) [ 3550.418285] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 3553.577928] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 3553.579970] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 3554.902527] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3617.482924] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 04:08:53 (1779696533) [ 3629.892280] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 3646.289382] Lustre: 116095:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3646.303279] Lustre: 116095:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 3668.037991] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3822.613132] Lustre: Failing over lustre-MDT0000 [ 3823.136562] Lustre: server umount lustre-MDT0000 complete [ 3827.568085] Lustre: Failing over lustre-MDT0001 [ 3827.570816] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3827.589144] LustreError: Skipped 1 previous similar message [ 3828.008597] Lustre: server umount lustre-MDT0001 complete [ 3833.931575] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3843.365851] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3846.623196] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779696748/real 1779696748] req@ffff9477c4755880 x1866143776748032/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779696764 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3846.660775] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 3851.831124] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3861.502211] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3872.340080] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3872.361990] Lustre: lustre-MDT0000: reset Object Index mappings [ 3872.365668] Lustre: Skipped 5 previous similar messages [ 3897.187076] LustreError: 82514: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. [ 3897.220455] LustreError: 82514:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 3897.308440] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3897.315337] Lustre: Skipped 2 previous similar messages [ 3897.365338] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3897.371201] Lustre: Skipped 1 previous similar message [ 3901.566312] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3910.342679] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3910.850243] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 3910.853190] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 3914.923355] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3914.928983] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3914.937862] Lustre: Skipped 1 previous similar message [ 3914.965130] Lustre: Skipped 10 previous similar messages [ 3915.006497] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3915.017794] Lustre: Skipped 1 previous similar message [ 3915.066625] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 3915.070374] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 3915.828951] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3925.372306] Lustre: *** cfs_fail_loc=190, val=1*** [ 3925.372943] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/64001: rc = 0 [ 3925.379282] Lustre: Skipped 39 previous similar messages [ 3928.631819] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32034 with flags 0x52: rc = 0 [ 3936.764464] Lustre: Failing over lustre-MDT0000 [ 3937.088997] Lustre: server umount lustre-MDT0000 complete [ 3941.292469] Lustre: Failing over lustre-MDT0001 [ 3941.586943] Lustre: server umount lustre-MDT0001 complete [ 3949.725285] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3950.879142] LustreError: 122002:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 3950.898636] LustreError: 122002:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff9477cdd40700 x1866143776784256/t0(0) o250->MGC192.168.204.160@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1779696869 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 projid:4294967295 [ 3950.924543] LustreError: 122002:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 3955.677758] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3965.022524] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3965.389785] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 3965.397147] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 3970.487299] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3970.660391] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 3970.660391] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:513) [ 3977.054167] Lustre: Failing over lustre-MDT0000 [ 3977.414475] Lustre: server umount lustre-MDT0000 complete [ 3981.572807] Lustre: Failing over lustre-MDT0001 [ 3981.918343] Lustre: server umount lustre-MDT0001 complete [ 3991.321072] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4011.931526] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4022.316192] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4022.700695] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 4022.730750] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 4027.760880] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4027.952191] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:545) [ 4027.954054] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 4043.656947] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 04:15:59 (1779696959) [ 4057.920357] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 4075.227313] Lustre: 126991:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4075.237516] Lustre: 126991:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 4096.543631] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4130.183754] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 04:17:25 (1779697045) [ 4135.356381] Lustre: *** cfs_fail_loc=195, val=0*** [ 4140.591900] Lustre: Failing over lustre-OST0000 [ 4140.843729] Lustre: server umount lustre-OST0000 complete [ 4141.026386] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4141.041447] LustreError: Skipped 7 previous similar messages [ 4141.043832] 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 [ 4141.065466] Lustre: Skipped 21 previous similar messages [ 4150.208725] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4156.590216] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4345.799252] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 04:21:01 (1779697261) [ 4349.446385] Lustre: *** cfs_fail_loc=196, val=0*** [ 4349.455590] Lustre: Skipped 63 previous similar messages [ 4355.055304] Lustre: Failing over lustre-OST0000 [ 4355.178124] Lustre: server umount lustre-OST0000 complete [ 4363.378180] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4370.349430] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4560.687733] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 04:24:36 (1779697476) [ 4568.689540] Lustre: *** cfs_fail_loc=196, val=0*** [ 4568.695457] Lustre: Skipped 63 previous similar messages [ 4570.836268] Lustre: *** cfs_fail_loc=196, val=0*** [ 4570.843169] Lustre: Skipped 191 previous similar messages [ 4575.307643] Lustre: *** cfs_fail_loc=196, val=0*** [ 4575.318494] Lustre: Skipped 319 previous similar messages [ 4590.839329] Lustre: Failing over lustre-OST0000 [ 4590.964195] Lustre: server umount lustre-OST0000 complete [ 4594.150626] LustreError: 87178: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. [ 4594.188646] LustreError: 87178:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 33 previous similar messages [ 4604.740935] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4605.206800] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4605.236851] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4605.254012] Lustre: Skipped 4 previous similar messages [ 4606.501533] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4606.511029] Lustre: Skipped 4 previous similar messages [ 4606.531535] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4606.535721] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4606.541454] Lustre: Skipped 4 previous similar messages [ 4606.555732] Lustre: Skipped 18 previous similar messages [ 4612.596952] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4625.889255] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4625.899103] Lustre: Skipped 2 previous similar messages [ 4627.052069] Lustre: server umount lustre-MDT0000 complete [ 4631.015051] LustreError: 75135:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779697549 with bad export cookie 2085859817974802170 [ 4631.021677] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4631.027599] LustreError: 75135:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 13 previous similar messages [ 4631.042617] LustreError: Skipped 2 previous similar messages [ 4631.331355] Lustre: server umount lustre-MDT0001 complete [ 4645.485944] Lustre: server umount lustre-OST0000 complete [ 4659.662374] Lustre: server umount lustre-OST0001 complete [ 4670.446540] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 04:26:26 (1779697586) [ 4688.995903] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_hostid [ 4697.233773] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 4743.813941] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 4754.818892] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4755.126056] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4755.178727] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4755.288193] Lustre: lustre-MDT0000: new disk, initializing [ 4755.418343] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4755.425846] Lustre: Skipped 7 previous similar messages [ 4755.453766] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4760.207545] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4771.676533] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4771.790983] Lustre: 138202: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 [ 4771.805448] Lustre: 138202:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 4771.862289] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4771.876165] Lustre: Skipped 1 previous similar message [ 4772.008391] Lustre: lustre-MDT0001: new disk, initializing [ 4772.143476] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4772.171679] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4777.288538] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4783.227215] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4791.074082] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4791.365453] Lustre: lustre-OST0000: new disk, initializing [ 4791.372439] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4791.378848] Lustre: 139800:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4792.830183] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4792.843394] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4793.006971] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4799.296936] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4811.438428] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4811.639219] Lustre: lustre-OST0001: new disk, initializing [ 4811.646793] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4811.656666] Lustre: 140656:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4813.669714] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4813.688446] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4813.812690] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4818.865243] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4828.903528] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4832.904208] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4854.452387] Lustre: Failing over lustre-MDT0000 [ 4854.758636] 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 [ 4854.774625] Lustre: Skipped 11 previous similar messages [ 4854.998947] Lustre: server umount lustre-MDT0000 complete [ 4859.363911] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4859.371143] LustreError: Skipped 3 previous similar messages [ 4859.768438] Lustre: Failing over lustre-MDT0001 [ 4859.888784] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4859.891643] Lustre: Skipped 1 previous similar message [ 4860.098648] Lustre: server umount lustre-MDT0001 complete [ 4866.422053] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4878.005764] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4888.032651] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4900.336410] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4912.684483] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4912.750639] Lustre: lustre-MDT0000: reset Object Index mappings [ 4912.757119] Lustre: Skipped 1 previous similar message [ 4934.899278] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4944.666743] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4945.369850] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 4945.374131] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 4950.520985] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4950.531053] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 4950.531494] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 5006.924243] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 04:32:03 (1779697923) [ 5023.199678] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 5070.967483] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5102.840822] Lustre: Failing over lustre-MDT0000 [ 5102.858388] Lustre: *** cfs_fail_loc=199, val=0*** [ 5102.864793] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5102.871714] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 5102.883587] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 5102.894283] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 5102.906114] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 5102.915754] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 5102.928143] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5102.936776] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5102.947313] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5102.956388] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5102.965503] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5102.976547] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5102.984327] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5102.995217] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5103.004635] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5103.013636] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5103.021600] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5103.029426] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5103.037034] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5103.046813] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 5103.054280] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5103.061594] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5103.069059] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5103.076498] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5103.083930] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5103.092406] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5103.102255] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5103.110651] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5103.116939] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5103.123906] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5103.129450] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5103.136134] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5103.141976] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5103.147827] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5103.154222] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5103.161670] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5103.169766] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 5103.176482] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 5103.182348] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 5103.188920] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 5103.194415] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 5103.200378] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 5103.206775] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5103.211801] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5103.218347] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5103.227209] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5103.237169] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5103.243815] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5103.248515] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 5103.254184] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 5103.260534] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 5103.269953] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 5103.276968] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 5103.283396] Lustre: 150341:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 5103.553719] Lustre: server umount lustre-MDT0000 complete [ 5107.967696] Lustre: Failing over lustre-MDT0001 [ 5107.999684] Lustre: *** cfs_fail_loc=199, val=0*** [ 5108.006806] Lustre: Skipped 53 previous similar messages [ 5108.013485] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 5108.032580] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 5108.047301] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 5108.064906] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 5108.079785] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 5108.094856] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 5108.110894] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 5108.126596] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 5108.139177] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 5108.149719] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 5108.154859] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 5108.160939] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 5108.167685] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 5108.173767] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 5108.181024] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 5108.187952] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 5108.198926] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 5108.206444] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 5108.218803] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 5108.229513] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 5108.235679] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 5108.245586] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 5108.253225] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 5108.259612] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 5108.268717] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 5108.278851] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 5108.298014] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 5108.310675] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 5108.327957] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 5108.346492] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 5108.363164] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 5108.389562] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 5108.427478] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 5108.450841] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 5108.461888] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 5108.475471] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 5108.493126] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 5108.511625] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 5108.530851] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 5108.545177] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 5108.558320] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 5108.566923] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 5108.578922] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 5108.588856] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 5108.601811] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 5108.620901] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 5108.633447] Lustre: 150542:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 5109.177780] Lustre: server umount lustre-MDT0001 complete [ 5121.709904] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5121.940810] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 5121.972943] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5122.005355] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 5122.023665] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 5122.049430] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 5122.073189] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 5122.093760] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 5122.107700] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 5122.126406] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 5122.161785] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 5122.185910] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 5122.199647] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 5122.219166] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 5122.237734] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 5122.251185] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 5122.277066] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 5122.304803] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 5122.353210] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 5122.373282] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 5122.388323] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 5122.400280] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 5122.423927] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 5122.453748] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 5122.474215] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 5122.496219] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 5122.506460] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 5122.518382] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 5122.537773] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 5122.548269] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 5122.576300] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 5122.610459] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 5122.625357] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 5122.638744] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 5122.652972] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 5122.680496] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 5122.705384] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 5122.721501] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 5122.740423] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 5122.763623] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 5122.778588] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 5122.795043] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 5122.813827] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 5122.825575] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 5122.844723] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 5122.862232] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 5122.878949] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 5122.893471] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 5122.915613] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 5122.923670] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 5122.934920] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 5122.942452] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 5122.950302] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 5122.956844] Lustre: 151039:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 5125.535183] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779698027/real 1779698027] req@ffff9478c458ea00 x1866143777506688/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779698043 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5125.588440] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 37 previous similar messages [ 5133.794980] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9478ea46b800 x1866143777508864/t0(0) o250->MGC192.168.204.160@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 [ 5139.693700] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5149.848706] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5150.005726] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 5150.022286] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 5150.037546] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 5150.054634] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 5150.073716] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 5150.089683] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 5150.114692] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 5150.141561] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 5150.218519] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 5150.246806] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 5150.273584] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 5150.297136] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 5150.313292] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 5150.336945] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 5150.361299] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 5150.391336] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 5150.413963] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 5150.439925] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 5150.474606] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 5150.512575] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 5150.539340] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 5150.563611] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 5150.579993] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 5150.593848] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 5150.613874] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 5150.631932] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 5150.648712] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 5150.676584] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 5150.691234] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 5150.709573] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 5150.729623] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 5150.743636] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 5150.763628] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 5150.778726] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 5150.795518] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 5150.805737] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 5150.814302] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 5150.826769] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 5150.836447] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 5150.844934] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 5150.852632] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 5150.884663] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 5150.895988] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 5150.907454] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 5150.928021] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 5150.954287] Lustre: 151769:0:(osd_scrub.c:1830:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 5151.473761] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 5151.477770] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 5156.986436] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 5156.987328] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 5158.050424] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5170.571306] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 04:34:46 (1779698086) [ 5171.760608] Lustre: *** cfs_fail_loc=19d, val=0*** [ 5171.772227] Lustre: Skipped 123 previous similar messages [ 5174.049822] Lustre: Failing over lustre-MDT0000 [ 5174.389684] Lustre: server umount lustre-MDT0000 complete [ 5192.371767] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5197.004227] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5198.349668] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 5198.351921] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 5200.840363] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 04:35:16 (1779698116) [ 5201.849197] Lustre: *** cfs_fail_loc=19e, val=0*** [ 5203.648820] Lustre: Failing over lustre-MDT0000 [ 5203.954895] Lustre: server umount lustre-MDT0000 complete [ 5207.681634] LustreError: 151054:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.60@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5207.702855] LustreError: 151054:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 56 previous similar messages [ 5220.900682] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5221.231312] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5221.248859] Lustre: Skipped 3 previous similar messages [ 5222.991018] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5222.998895] Lustre: Skipped 3 previous similar messages [ 5225.499864] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5226.478484] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5226.487185] Lustre: Skipped 15 previous similar messages [ 5226.515193] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5226.545097] Lustre: Skipped 3 previous similar messages [ 5226.628588] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 5226.634854] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 5229.526454] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 04:35:45 (1779698145) [ 5253.566252] Lustre: Failing over lustre-MDT0000 [ 5254.018904] Lustre: server umount lustre-MDT0000 complete [ 5258.750263] LustreError: 138195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779698176 with bad export cookie 2085859817974969568 [ 5258.750952] Lustre: Failing over lustre-MDT0001 [ 5258.751926] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5258.751933] LustreError: Skipped 4 previous similar messages [ 5258.760915] LustreError: 138195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 5259.230385] Lustre: server umount lustre-MDT0001 complete [ 5268.735442] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5278.687145] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779698180/real 1779698180] req@ffff9478c76c2a00 x1866143777666048/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779698196 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5278.731259] Lustre: 16285:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 5282.847836] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9478c76c1500 x1866143777668096/t0(0) o250->MGC192.168.204.160@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 [ 5287.976366] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5299.662857] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5299.944948] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 5299.951141] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 5304.783434] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5305.443661] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 5305.446577] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 5312.277869] Lustre: Failing over lustre-MDT0000 [ 5312.666558] Lustre: server umount lustre-MDT0000 complete [ 5316.983505] Lustre: Failing over lustre-MDT0001 [ 5317.396664] Lustre: server umount lustre-MDT0001 complete [ 5326.894846] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5342.179050] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x1cf27673fda9248c [ 5346.960890] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5357.913181] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5358.345471] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5358.355623] Lustre: Skipped 12 previous similar messages [ 5358.399430] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 5358.422797] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 5363.804931] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:289) [ 5363.808829] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 5364.544490] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5376.447956] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 04:38:12 (1779698292) [ 5385.110895] Lustre: server umount lustre-MDT0000 complete [ 5389.288170] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5391.256711] Lustre: server umount lustre-MDT0001 complete [ 5395.130530] Lustre: server umount lustre-OST0000 complete [ 5398.828520] Lustre: server umount lustre-OST0001 complete [ 5405.145515] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5414.177814] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5429.791481] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5434.911318] LustreError: 160417:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.160@tcp: failed processing log, type 4: rc = -110 [ 5468.331206] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5474.279868] Lustre: Failing over lustre-OST0000 [ 5474.423704] Lustre: server umount lustre-OST0000 complete [ 5480.500658] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5490.287997] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5505.887463] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 5511.008075] LustreError: 161926:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.160@tcp: failed processing log, type 4: rc = -110 [ 5542.764462] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5550.512254] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 04:41:06 (1779698466) [ 5563.786406] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 5573.495070] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5574.055915] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 5578.174670] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5586.881851] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5587.108991] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:257) [ 5590.494319] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5593.164601] Lustre: 164766:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5593.172046] Lustre: 164766:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 2 previous similar messages [ 5608.730216] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5614.071033] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 5614.078241] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:257) [ 5615.530987] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5623.309721] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5628.831047] Lustre: *** cfs_fail_loc=193, val=0*** [ 5630.720554] Lustre: Failing over lustre-MDT0000 [ 5630.904524] Lustre: *** cfs_fail_loc=193, val=0*** [ 5631.109668] Lustre: server umount lustre-MDT0000 complete [ 5633.508591] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5633.521329] LustreError: Skipped 9 previous similar messages [ 5633.527875] 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 [ 5633.549386] Lustre: Skipped 33 previous similar messages [ 5640.026413] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5640.382938] Lustre: *** cfs_fail_loc=193, val=0*** [ 5645.120495] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5645.893527] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 5645.893929] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 5649.610945] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5649.614402] Lustre: Skipped 4 previous similar messages [ 5649.621245] Lustre: *** cfs_fail_loc=19f, val=0*** [ 5649.624254] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 5649.624373] Lustre: Skipped 79 previous similar messages [ 5664.573806] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 04:43:00 (1779698580) [ 5667.607131] Lustre: Failing over lustre-MDT0000 [ 5667.840370] Lustre: server umount lustre-MDT0000 complete [ 5671.498653] Lustre: Failing over lustre-MDT0001 [ 5671.754768] Lustre: server umount lustre-MDT0001 complete [ 5674.372926] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5681.970606] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5691.871225] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779698594/real 1779698594] req@ffff9478ee557b80 x1866143777872896/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779698610 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5691.891827] Lustre: 16287:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 5696.031515] LustreError: 16284:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9478ee554e00 x1866143777874560/t0(0) o250->MGC192.168.204.160@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 [ 5701.146591] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5709.831811] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5711.375331] LustreError: 169217:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 5711.480259] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:289) [ 5711.485789] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:289) [ 5711.534830] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 5711.538206] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 5715.353815] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5721.071106] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 5727.871195] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 04:44:03 (1779698643) [ 5731.811159] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5731.822437] Lustre: Skipped 4 previous similar messages [ 5737.847791] Lustre: server umount lustre-MDT0000 complete [ 5741.542315] Lustre: server umount lustre-MDT0001 complete [ 5755.704162] Lustre: server umount lustre-OST0000 complete [ 5759.954355] Lustre: server umount lustre-OST0001 complete [ 5767.475788] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5780.649321] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5786.120696] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5792.089831] Lustre: Failing over lustre-MDT0000 [ 5792.099500] LustreError: 171574:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5792.111268] LustreError: 171574:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5792.128510] LustreError: 171574:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 11, retries 0, failed: rc = -5 [ 5792.648721] Lustre: server umount lustre-MDT0000 complete [ 5800.295288] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5815.120501] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5815.620470] LustreError: 173161: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. [ 5815.629246] LustreError: 173161:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 91 previous similar messages [ 5820.282796] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5829.064659] Lustre: DEBUG MARKER: === sanity-scrub: start setup 04:45:45 (1779698745) === [ 5831.603465] LustreError: 173194:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 5831.612989] LustreError: 173194:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 5831.624642] LustreError: 173194:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 16, retries 0, failed: rc = -5 [ 5832.305272] Lustre: server umount lustre-MDT0000 complete [ 5873.297747] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_hostid [ 5882.302218] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 5937.968143] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing load_modules_local [ 5952.942038] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5953.367730] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5953.433624] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5953.523521] Lustre: lustre-MDT0000: new disk, initializing [ 5953.643922] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5959.785017] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5975.782511] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5975.979352] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5975.987540] Lustre: Skipped 1 previous similar message [ 5976.112052] Lustre: lustre-MDT0001: new disk, initializing [ 5976.200154] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5976.207364] Lustre: Skipped 11 previous similar messages [ 5976.284020] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5976.300904] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5981.457156] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5987.603743] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5998.323691] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5998.559193] Lustre: lustre-OST0000: new disk, initializing [ 5998.564430] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5998.573913] Lustre: 180398:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6000.330762] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6000.340572] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6000.471496] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6006.332369] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6021.992196] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6022.219961] Lustre: lustre-OST0001: new disk, initializing [ 6022.228740] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6022.239161] Lustre: 181407:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6024.040163] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6024.054801] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6024.171244] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6029.120632] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6039.348317] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6043.812097] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6049.882129] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 04:49:25 (1779698965) === [ 6051.324398] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 5721 sec ========= 04:49:27 (1779698967) [ 6053.428636] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 04:49:29 (1779698969) === [ 6058.656708] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 04:49:33 (1779698973) === [ 6065.122243] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6065.141817] Lustre: Skipped 7 previous similar messages [ 6070.062590] Lustre: server umount lustre-MDT0000 complete [ 6079.126697] LustreError: 178484:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779698997 with bad export cookie 2085859817975025183 [ 6079.129141] LustreError: MGC192.168.204.160@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6079.139176] LustreError: 178484:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 15 previous similar messages [ 6079.149802] LustreError: Skipped 5 previous similar messages [ 6079.552419] Lustre: server umount lustre-MDT0001 complete [ 6096.671850] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779698998/real 1779698998] req@ffff9478ff92e300 x1866143777999616/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779699014 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6096.726895] Lustre: 16288:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 9 previous similar messages [ 6098.906244] Lustre: server umount lustre-OST0000 complete [ 6108.465770] Lustre: server umount lustre-OST0001 complete [ 6126.759136] Lustre: DEBUG MARKER: oleg460-server.virtnet: executing unload_modules_local [ 6130.001923] Key type lgssc unregistered [ 6130.352972] LNet: 184784:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6130.369026] LNetError: 184784:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6130.383864] LNet: Removed LNI 192.168.204.160@tcp [ 6131.621152] Key type .llcrypt unregistered [ 6131.625788] Key type ._llcrypt unregistered