[ 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 491877831 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: 2856328K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524588K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003154] x2apic enabled [ 0.004007] Switched APIC routing to physical x2apic. [ 0.005017] kvm-guest: setup PV IPIs [ 0.008480] ..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.009028] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010013] pid_max: default: 32768 minimum: 301 [ 0.011163] LSM: Security Framework initializing [ 0.012056] Yama: becoming mindful. [ 0.013043] SELinux: Initializing. [ 0.014069] *** VALIDATE selinux *** [ 0.022860] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028599] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029154] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030133] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031125] *** VALIDATE tmpfs *** [ 0.033054] *** VALIDATE proc *** [ 0.034215] *** VALIDATE cgroup *** [ 0.035009] *** VALIDATE cgroup2 *** [ 0.036275] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038086] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039007] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040023] Spectre V2 : User space: Vulnerable [ 0.041011] Speculative Store Bypass: Vulnerable [ 0.043654] debug: unmapping init [mem 0xffffffff87c59000-0xffffffff87c60fff] [ 0.045185] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046709] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047027] ... version: 2 [ 0.048013] ... bit width: 48 [ 0.049012] ... generic registers: 4 [ 0.050011] ... value mask: 0000ffffffffffff [ 0.051017] ... max period: 00007fffffffffff [ 0.052017] ... fixed-purpose events: 3 [ 0.053012] ... event mask: 000000070000000f [ 0.054310] rcu: Hierarchical SRCU implementation. [ 0.056473] smp: Bringing up secondary CPUs ... [ 0.057612] x86: Booting SMP configuration: [ 0.058027] .... node #0, CPUs: #1 #2 #3 [ 0.064473] smp: Brought up 1 node, 4 CPUs [ 0.066013] smpboot: Max logical packages: 1 [ 0.067017] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.130191] node 0 deferred pages initialised in 61ms [ 0.134156] devtmpfs: initialized [ 0.135180] x86/mm: Memory block size: 128MB [ 0.137961] gcov: version magic: 0x41383552 [ 0.139259] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.140089] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.141215] pinctrl core: initialized pinctrl subsystem [ 0.142160] [ 0.142493] ************************************************************* [ 0.143009] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.144009] ** ** [ 0.145011] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.146008] ** ** [ 0.147007] ** This means that this kernel is built to expose internal ** [ 0.148009] ** IOMMU data structures, which may compromise security on ** [ 0.149010] ** your system. ** [ 0.150012] ** ** [ 0.151008] ** If you see this message and you are not debugging the ** [ 0.152008] ** kernel, report this immediately to your vendor! ** [ 0.153008] ** ** [ 0.154008] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.155010] ************************************************************* [ 0.156784] NET: Registered protocol family 16 [ 0.157317] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.158037] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.159032] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.160356] cpuidle: using governor menu [ 0.161527] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.163380] PCI: Using configuration type 1 for base access [ 0.165117] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.174176] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.176020] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.179142] cryptd: max_cpu_qlen set to 1000 [ 0.181479] ACPI: Added _OSI(Module Device) [ 0.183019] ACPI: Added _OSI(Processor Device) [ 0.185018] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.186013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.192452] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.199189] ACPI: Interpreter enabled [ 0.200061] ACPI: PM: (supports S0 S3 S4 S5) [ 0.202013] ACPI: Using IOAPIC for interrupt routing [ 0.204112] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.208435] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.218608] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.221047] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.224024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.227140] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.233589] acpiphp: Slot [2] registered [ 0.235128] acpiphp: Slot [5] registered [ 0.237151] acpiphp: Slot [6] registered [ 0.238194] acpiphp: Slot [7] registered [ 0.239115] acpiphp: Slot [8] registered [ 0.241126] acpiphp: Slot [9] registered [ 0.243124] acpiphp: Slot [10] registered [ 0.244133] acpiphp: Slot [3] registered [ 0.246224] acpiphp: Slot [4] registered [ 0.248137] acpiphp: Slot [11] registered [ 0.249120] acpiphp: Slot [12] registered [ 0.251192] acpiphp: Slot [13] registered [ 0.252110] acpiphp: Slot [14] registered [ 0.253117] acpiphp: Slot [15] registered [ 0.255111] acpiphp: Slot [16] registered [ 0.257124] acpiphp: Slot [17] registered [ 0.258123] acpiphp: Slot [18] registered [ 0.260135] acpiphp: Slot [19] registered [ 0.261172] acpiphp: Slot [20] registered [ 0.262165] acpiphp: Slot [21] registered [ 0.264114] acpiphp: Slot [22] registered [ 0.266106] acpiphp: Slot [23] registered [ 0.267160] acpiphp: Slot [24] registered [ 0.269158] acpiphp: Slot [25] registered [ 0.271144] acpiphp: Slot [26] registered [ 0.272130] acpiphp: Slot [27] registered [ 0.273180] acpiphp: Slot [28] registered [ 0.275107] acpiphp: Slot [29] registered [ 0.276134] acpiphp: Slot [30] registered [ 0.278093] acpiphp: Slot [31] registered [ 0.279050] PCI host bridge to bus 0000:00 [ 0.280017] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.283036] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.285026] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.288046] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.291053] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.294029] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.296191] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.300000] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.303399] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.314770] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.319067] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.322025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.325029] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.328020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.330578] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.333904] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.336059] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.339922] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.345014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.357020] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.363024] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.369289] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.379015] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.389017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.409019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.420951] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.428018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.437023] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.451019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.460489] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.466011] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.473019] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.484014] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.491829] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.499016] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.507016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.528016] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.538850] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.547015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.559023] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.576020] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.586121] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.595017] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.602018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.620018] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.630994] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.633538] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.636477] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.639428] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.642228] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.646039] iommu: Default domain type: Passthrough [ 0.647576] SCSI subsystem initialized [ 0.649128] ACPI: bus type USB registered [ 0.650081] usbcore: registered new interface driver usbfs [ 0.651073] usbcore: registered new interface driver hub [ 0.653069] usbcore: registered new device driver usb [ 0.654156] pps_core: LinuxPPS API ver. 1 registered [ 0.655009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.657060] PTP clock support registered [ 0.659119] EDAC MC: Ver: 3.0.0 [ 0.661162] PCI: Using ACPI for IRQ routing [ 0.662843] NetLabel: Initializing [ 0.664013] NetLabel: domain hash size = 128 [ 0.665009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.667083] NetLabel: unlabeled traffic allowed by default [ 0.669154] vgaarb: loaded [ 0.671255] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.673011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.679294] clocksource: Switched to clocksource kvm-clock [ 0.778200] VFS: Disk quotas dquot_6.6.0 [ 0.779789] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.781820] *** VALIDATE ramfs *** [ 0.783929] *** VALIDATE hugetlbfs *** [ 0.785293] pnp: PnP ACPI init [ 0.787611] pnp: PnP ACPI: found 6 devices [ 0.803134] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.806516] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.808867] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.811281] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.813668] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.815753] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.817938] NET: Registered protocol family 2 [ 0.820570] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.824923] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.828753] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.834278] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.837695] TCP: Hash tables configured (established 65536 bind 65536) [ 0.840834] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.844386] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.847238] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.850247] NET: Registered protocol family 1 [ 0.852442] RPC: Registered named UNIX socket transport module. [ 0.854361] RPC: Registered udp transport module. [ 0.855645] RPC: Registered tcp transport module. [ 0.857358] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.860144] NET: Registered protocol family 44 [ 0.861919] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.864243] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.866540] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.868932] PCI: CLS 0 bytes, default 64 [ 0.871461] Unpacking initramfs... [ 2.240934] debug: unmapping init [mem 0xffff962efcc54000-0xffff962efffbffff] [ 2.243483] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.244813] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.246498] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.710153] Initialise system trusted keyrings [ 2.711721] Key type blacklist registered [ 2.713432] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.722066] zbud: loaded [ 2.725107] *** VALIDATE nfs *** [ 2.726282] *** VALIDATE nfs4 *** [ 2.728125] pstore: using deflate compression [ 2.737109] Platform Keyring initialized [ 2.820280] NET: Registered protocol family 38 [ 2.822325] Key type asymmetric registered [ 2.823818] Asymmetric key parser 'x509' registered [ 2.825780] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.828968] io scheduler mq-deadline registered [ 2.830767] io scheduler kyber registered [ 2.832501] io scheduler bfq registered [ 2.834445] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.837449] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.840613] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.843703] ACPI: Power Button [PWRF] [ 2.849010] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.856798] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.871123] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.877948] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.893130] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.920993] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.949766] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.954225] Non-volatile memory driver v1.3 [ 2.955561] Linux agpgart interface v0.103 [ 2.988901] virtio_blk virtio1: [vda] 150008 512-byte logical blocks (76.8 MB/73.2 MiB) [ 2.991873] vda: detected capacity change from 0 to 76804096 [ 3.004620] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.007306] vdb: detected capacity change from 0 to 1073741824 [ 3.020815] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.023986] vdc: detected capacity change from 0 to 2621440000 [ 3.039905] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.042919] vdd: detected capacity change from 0 to 2621440000 [ 3.058376] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.061761] vde: detected capacity change from 0 to 4294967296 [ 3.074970] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.078067] vdf: detected capacity change from 0 to 4294967296 [ 3.083994] libphy: Fixed MDIO Bus: probed [ 3.094122] usbcore: registered new interface driver usbserial_generic [ 3.096141] usbserial: USB Serial support registered for generic [ 3.098522] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.102786] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.104758] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.107222] mousedev: PS/2 mouse device common for all mice [ 3.109946] rtc_cmos 00:05: RTC can wake from S4 [ 3.112420] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.113265] rtc_cmos 00:05: registered as rtc0 [ 3.118118] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.118729] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.121408] intel_pstate: CPU model not supported [ 3.127577] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.131971] hid: raw HID events driver (C) Jiri Kosina [ 3.134271] usbcore: registered new interface driver usbhid [ 3.136240] usbhid: USB HID core driver [ 3.137921] drop_monitor: Initializing network drop monitor service [ 3.140436] Initializing XFRM netlink socket [ 3.142673] NET: Registered protocol family 10 [ 3.145845] Segment Routing with IPv6 [ 3.147487] NET: Registered protocol family 17 [ 3.149597] mpls_gso: MPLS GSO support [ 3.156557] RAS: Correctable Errors collector initialized. [ 3.158921] AVX version of gcm_enc/dec engaged. [ 3.160629] AES CTR mode by8 optimization enabled [ 3.237164] sched_clock: Marking stable (3237138421, 0)->(4150058850, -912920429) [ 3.240286] registered taskstats version 1 [ 3.242164] Loading compiled-in X.509 certificates [ 3.243837] zswap: loaded using pool lzo/zbud [ 3.264610] Key type big_key registered [ 3.275810] Key type encrypted registered [ 3.277766] ima: No TPM chip found, activating TPM-bypass! [ 3.279487] ima: Allocated hash algorithm: sha1 [ 3.281034] ima: No architecture policies found [ 3.284130] evm: Initialising EVM extended attributes: [ 3.286008] evm: security.selinux [ 3.287336] evm: security.ima [ 3.288529] evm: security.capability [ 3.289902] evm: HMAC attrs: 0x1 [ 3.292154] rtc_cmos 00:05: setting system clock to 2026-09-15 04:14:07 UTC (1789445647) [ 3.298130] debug: unmapping init [mem 0xffffffff88c03000-0xffffffff88dfffff] [ 3.301029] debug: unmapping init [mem 0xffffffff87982000-0xffffffff87c58fff] [ 3.313225] Write protecting the kernel read-only data: 28672k [ 3.316657] debug: unmapping init [mem 0xffffffff86003000-0xffffffff861fffff] [ 3.319550] debug: unmapping init [mem 0xffffffff86914000-0xffffffff869fffff] [ 3.358386] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.367442] systemd[1]: Detected virtualization kvm. [ 3.368812] systemd[1]: Detected architecture x86-64. [ 3.370338] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.394699] systemd[1]: No hostname configured. [ 3.395984] systemd[1]: Set hostname to . [ 3.397571] random: systemd: uninitialized urandom read (16 bytes read) [ 3.399461] systemd[1]: Initializing machine ID from random generator. [ 3.450528] random: ln: uninitialized urandom read (6 bytes read) [ 3.543175] random: systemd: uninitialized urandom read (16 bytes read) [ 3.545515] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.549594] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.556870] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Swap. Starting Apply Kernel Variables... [ OK ] Reached target Initrd Root Device. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. [ OK ] Reached target Slices. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook...[ 4.088206] random: fast init done [ 4.133965] device-mapper: uevent: version 1.0.3 [ 4.136552] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.915103] virtio_net virtio0 ens2: renamed from eth0 Starting dracut initqueue hook... [ 5.092547] scsi host0: ata_piix [ 5.127329] scsi host1: ata_piix [ 5.129060] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.131353] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.880521] dracut-initqueue[585]: RTNETLINK answers: File exists [ 9.795632] random: crng init done [ 9.797064] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.315657] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ 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 Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.530583] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.788506] SELinux: Disabled at runtime. [ 11.855737] 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) [ 11.863803] systemd[1]: Detected virtualization kvm. [ 11.865687] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.466746] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.469748] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.475138] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.479419] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.482528] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.492383] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.495809] systemd[1]: Reached target rpc_pipefs.target. [ OK ] Reached target rpc_pipefs.target. Mounting Kernel Debug File System... [ OK ] Created slice system-getty.slice. [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice User and Session Slice. [ OK ] Listening on udev Control Socket. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Mounting Huge Pages File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... Activating swap /dev/disk/by-label/SWAP... Starting Apply Kernel Variables... Starting Remount Root and Kernel File Systems... [ OK ] Listening on RPCbind Server Ac[ 12.612680] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS tivation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Created slice system-sshd\x2dkeygen.slice. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting POSIX Message Queue File System... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ 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 Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.976978] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.316253] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.365789] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.484759] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.495985] EDAC sbridge: Ver: 1.1.2 [ 15.120767] Key type dns_resolver registered [ 15.413212] NFS: Registering the id_resolver key type [ 15.415386] Key type id_resolver registered [ 15.417165] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ 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 update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg208-server login: [ 41.555367] libcfs: loading out-of-tree module taints kernel. [ 41.575916] Key type ._llcrypt registered [ 41.577669] Key type .llcrypt registered [ 41.631903] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 54.586943] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 56.808467] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 56.845196] alg: No test for adler32 (adler32-zlib) [ 58.332383] Lustre: Lustre: Build Version: 2.17.58_39_ge07ba0b [ 59.577536] LNet: Added LNI 192.168.202.108@tcp [8/256/0/180] [ 61.311268] Key type lgssc registered [ 64.009929] Lustre: Echo OBD driver; http://www.lustre.org/ [ 78.381463] hrtimer: interrupt took 8449776 ns [ 86.558476] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 133.465292] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 149.773787] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 149.821265] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 151.227888] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 151.262444] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 151.351542] Lustre: lustre-MDT0000: new disk, initializing [ 151.452938] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 151.478922] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 156.505881] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 171.302612] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 171.403965] Lustre: 6490:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 171.429617] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 171.433244] Lustre: Skipped 1 previous similar message [ 171.511374] Lustre: lustre-MDT0001: new disk, initializing [ 171.573376] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 171.601581] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 171.621142] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 176.726443] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 181.456676] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 191.732267] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 191.987849] Lustre: lustre-OST0000: new disk, initializing [ 191.991433] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 191.998750] Lustre: 8434:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 192.011617] Lustre: lustre-OST0000: Not available for connect from 0@lo (not set up) [ 192.024500] Lustre: Skipped 1 previous similar message [ 192.080456] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 197.116946] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 197.137495] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 197.196858] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 198.868928] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 214.304946] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 214.440381] Lustre: lustre-OST0001: new disk, initializing [ 214.443773] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 214.448733] Lustre: 9504:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 214.508915] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 221.118153] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 224.901213] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 224.920403] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 225.022492] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 234.201385] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 242.595772] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 249.486601] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing check_logdir /tmp/testlogs/ [ 255.131958] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing yml_node [ 260.436649] Lustre: DEBUG MARKER: Client: 2.17.58.39 [ 263.506218] Lustre: DEBUG MARKER: MDS: 2.17.58.39 [ 265.926650] Lustre: DEBUG MARKER: OSS: 2.17.58.39 [ 267.596341] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Tue Sep 15 00:18:31 EDT 2026 [ 285.617528] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 297.543863] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 307.169201] 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 [ 307.171079] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 307.190984] Lustre: Skipped 1 previous similar message [ 307.200030] Lustre: Skipped 3 previous similar messages [ 312.256332] Lustre: server umount lustre-MDT0000 complete [ 312.293120] LustreError: 6497:0:(ldlm_lib.c:1199: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. [ 312.311459] LustreError: 6497:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 317.412214] LustreError: 6498:0:(ldlm_lib.c:1199: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. [ 317.426546] LustreError: 6498:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 320.220657] LustreError: 6483:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789445964 with bad export cookie 14518555363306371985 [ 320.223212] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 320.232208] LustreError: 6483:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 320.802068] Lustre: server umount lustre-MDT0001 complete [ 337.888820] Lustre: 3621:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789445966/real 1789445966] req@ffff962f7d718a80 x1876369817572864/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789445982 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 337.920903] 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 [ 337.962836] Lustre: Skipped 2 previous similar messages [ 340.959363] Lustre: 3624:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789445969/real 1789445969] req@ffff962f7d4d9f80 x1876369817573120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789445985 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 341.210442] Lustre: server umount lustre-OST0000 complete [ 343.142495] Lustre: 3621:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789445971/real 1789445971] req@ffff962f4466ad80 x1876369817573376/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789445987 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 346.081100] Lustre: 3624:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789445974/real 1789445974] req@ffff962f44669f80 x1876369817573760/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789445990 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 351.410651] Lustre: server umount lustre-OST0001 complete [ 368.901110] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing unload_modules_local [ 371.856886] Key type lgssc unregistered [ 372.227980] LNet: 14775:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 372.231972] LNetError: 14775:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 372.263250] LNet: Removed LNI 192.168.202.108@tcp [ 373.327034] Key type .llcrypt unregistered [ 373.329907] Key type ._llcrypt unregistered [ 399.791608] Key type ._llcrypt registered [ 399.794510] Key type .llcrypt registered [ 399.987923] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 419.577450] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 421.346988] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 421.395297] alg: No test for adler32 (adler32-zlib) [ 422.608834] Lustre: Lustre: Build Version: 2.17.58_39_ge07ba0b [ 422.795990] LNet: Added LNI 192.168.202.108@tcp [8/256/0/180] [ 424.503308] Key type lgssc registered [ 426.007248] Lustre: Echo OBD driver; http://www.lustre.org/ [ 489.494621] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 504.335481] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 504.360517] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 505.754421] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 505.803215] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 505.912347] Lustre: lustre-MDT0000: new disk, initializing [ 506.007042] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 506.018699] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 510.873651] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 525.681526] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 525.764338] Lustre: 19233:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 525.797780] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 525.800845] Lustre: Skipped 1 previous similar message [ 525.891111] Lustre: lustre-MDT0001: new disk, initializing [ 525.996995] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 526.032553] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 526.037039] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 530.182066] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 534.854919] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 544.579616] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 544.780501] Lustre: lustre-OST0000: new disk, initializing [ 544.787775] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 544.793828] Lustre: 21172:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 544.893714] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 551.119569] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 553.995664] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 554.005761] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 554.083884] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 564.255055] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 564.452634] Lustre: lustre-OST0001: new disk, initializing [ 564.456330] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 564.461771] Lustre: 22197:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 564.581465] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 570.523615] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 573.473330] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 573.479547] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 573.553240] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 583.137635] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 591.820774] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 600.874950] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 00:24:03 (1789446243) === [ 604.644397] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 00:24:07 (1789446247) [ 604.934775] Lustre: 21904:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 604.951248] Lustre: 21904:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 604.959651] Lustre: 21904:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 604.966694] Lustre: 21904:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 604.975285] Lustre: 21904:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 604.980381] Lustre: 21904:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 605.568623] Lustre: 19238:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 605.579090] Lustre: 19238:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 11 previous similar messages [ 605.593367] Lustre: 19238:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 605.601084] Lustre: 19238:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 605.610743] Lustre: 19238:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 605.618637] Lustre: 19238:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 605.623950] Lustre: 19238:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 605.629571] Lustre: 19238:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 605.641963] Lustre: 19238:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 605.647889] Lustre: 19238:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 605.659824] Lustre: 19238:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 605.674735] Lustre: 19238:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 606.637977] Lustre: 19239:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 606.646641] Lustre: 19239:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 38 previous similar messages [ 606.652793] Lustre: 19239:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 606.659838] Lustre: 19239:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 606.666936] Lustre: 19239:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 606.673797] Lustre: 19239:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 606.683429] Lustre: 19239:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 606.694441] Lustre: 19239:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 606.701339] Lustre: 19239:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 606.707645] Lustre: 19239:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 606.714418] Lustre: 19239:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 606.719843] Lustre: 19239:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 608.668661] Lustre: 19238:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 608.673336] Lustre: 19238:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 104 previous similar messages [ 608.676465] Lustre: 19238:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 608.680985] Lustre: 19238:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 608.686712] Lustre: 19238:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 608.694222] Lustre: 19238:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 608.700105] Lustre: 19238:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 608.704826] Lustre: 19238:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 608.709311] Lustre: 19238:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 608.713086] Lustre: 19238:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 608.721358] Lustre: 19238:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 608.726642] Lustre: 19238:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 612.896533] Lustre: *** cfs_fail_loc=1600, val=3*** [ 615.904950] Lustre: *** cfs_fail_loc=1600, val=3*** [ 615.946846] Lustre: 23383:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 615.949491] Lustre: 23384:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 615.984252] Lustre: 23383:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 130 previous similar messages [ 615.984285] Lustre: 23383:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 615.984290] Lustre: 23383:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 129 previous similar messages [ 615.984296] Lustre: 23383:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 615.984299] Lustre: 23383:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 129 previous similar messages [ 615.984305] Lustre: 23383:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 615.984308] Lustre: 23383:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 129 previous similar messages [ 615.984314] Lustre: 23383:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 615.984317] Lustre: 23383:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 129 previous similar messages [ 616.119619] Lustre: 23384:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 137 previous similar messages [ 618.856166] Lustre: *** cfs_fail_loc=1600, val=3*** [ 631.297645] Lustre: 21158:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 631.302986] Lustre: 23596:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 631.326986] Lustre: 21158:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 54 previous similar messages [ 631.331552] Lustre: 23596:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 631.331576] Lustre: 23596:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 631.331580] Lustre: 23596:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 631.331586] Lustre: 23596:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 631.331589] Lustre: 23596:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 631.331594] Lustre: 23596:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 631.331597] Lustre: 23596:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 631.331603] Lustre: 23596:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 631.331607] Lustre: 23596:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 633.826108] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 633.838367] 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 [ 633.857453] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 634.848901] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 634.870163] 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 [ 634.900739] Lustre: Skipped 1 previous similar message [ 639.975615] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 639.984599] Lustre: Skipped 6 previous similar messages [ 645.090085] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 648.159210] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 650.354808] Lustre: server umount lustre-MDT0000 complete [ 654.576400] LustreError: 19222:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789446298 with bad export cookie 14699189726451768958 [ 654.578500] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 654.591759] LustreError: 19222:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 654.972296] Lustre: server umount lustre-MDT0001 complete [ 669.906147] Lustre: server umount lustre-OST0000 complete [ 671.520074] Lustre: 16388:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789446299/real 1789446299] req@ffff962e4c767b80 x1876370198217856/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789446315 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 671.552685] 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 [ 671.564739] Lustre: Skipped 1 previous similar message [ 674.373398] Lustre: server umount lustre-OST0001 complete [ 686.113744] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 00:25:29 (1789446329) [ 702.864587] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 714.522933] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 715.137727] LustreError: 26257:0:(ldlm_lib.c:1199: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. [ 715.172517] LustreError: 26257:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 715.276897] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 720.353046] LustreError: 26258:0:(ldlm_lib.c:1199: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. [ 721.282233] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 725.472208] LustreError: 26257:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 730.617514] LustreError: 26258:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 733.339544] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 734.087860] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 740.822812] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 744.285101] Lustre: 27398:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 753.003416] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 753.512018] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 759.655422] LustreError: 27752:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: 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. [ 760.681225] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 761.183580] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 771.042377] LustreError: 27753:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: 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. [ 771.072422] LustreError: 27753:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 774.116135] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 779.760285] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:40 to 0x2c0000401:65) [ 781.295465] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 789.329245] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 793.177559] Lustre: 29272:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 794.894816] Lustre: 29135:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 794.901926] Lustre: 29135:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2 previous similar messages [ 794.909822] Lustre: 29135:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 794.917663] Lustre: 29135:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 794.921909] Lustre: 29135:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 794.926557] Lustre: 29135:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 794.932575] Lustre: 29135:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 794.937752] Lustre: 29135:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 794.941939] Lustre: 29135:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 794.951771] Lustre: 29135:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 794.968220] Lustre: 29135:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 794.983550] Lustre: 29135:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 800.288933] Lustre: *** cfs_fail_loc=1501, val=0*** [ 809.529818] Lustre: Failing over lustre-MDT0000 [ 809.835947] Lustre: server umount lustre-MDT0000 complete [ 810.468858] 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 [ 810.474899] LustreError: 26254:0:(ldlm_lib.c:1199: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. [ 810.485374] Lustre: Skipped 1 previous similar message [ 810.525966] LustreError: 26254:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 822.971564] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 823.067956] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 823.366107] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 823.377618] Lustre: Skipped 1 previous similar message [ 823.418883] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 828.209704] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 828.385204] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 828.395424] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 828.418856] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 828.466433] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 828.466705] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 832.118475] Lustre: *** cfs_fail_loc=1505, val=0*** [ 839.930508] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 00:28:03 (1789446483) [ 841.231679] Lustre: 26253:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 841.242107] Lustre: 26253:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 841.245671] Lustre: 26253:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 841.252530] Lustre: 26253:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 841.257246] Lustre: 26253:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 841.262289] Lustre: 26253:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 841.266156] Lustre: 26253:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 841.271149] Lustre: 26253:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 841.275641] Lustre: 26253:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 841.279894] Lustre: 26253:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 841.284354] Lustre: 26253:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 841.288897] Lustre: 26253:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 846.791799] Lustre: *** cfs_fail_loc=1502, val=0*** [ 857.021440] Lustre: Failing over lustre-MDT0000 [ 857.326185] Lustre: server umount lustre-MDT0000 complete [ 859.110780] 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 [ 859.113896] LustreError: 29135:0:(ldlm_lib.c:1199: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. [ 859.120315] Lustre: Skipped 3 previous similar messages [ 859.145288] LustreError: 29135:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [ 868.406459] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 868.475528] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 868.726300] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 872.727926] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 873.956261] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 873.962353] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 873.979976] Lustre: Skipped 3 previous similar messages [ 873.993400] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 874.038631] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 874.041626] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 876.058299] Lustre: *** cfs_fail_loc=1505, val=0*** [ 884.167289] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 00:28:47 (1789446527) [ 891.353659] Lustre: *** cfs_fail_loc=1504, val=0*** [ 891.360862] Lustre: *** cfs_fail_loc=1504, val=0*** [ 891.362577] Lustre: Skipped 1 previous similar message [ 900.069077] Lustre: Failing over lustre-MDT0000 [ 900.318703] Lustre: server umount lustre-MDT0000 complete [ 904.674673] 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 [ 904.692435] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 904.696629] Lustre: Skipped 3 previous similar messages [ 911.506711] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 911.635974] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 911.897960] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 911.910911] Lustre: Skipped 1 previous similar message [ 911.989122] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 916.298386] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 916.965518] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 916.967721] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 916.980558] Lustre: Skipped 3 previous similar messages [ 916.994757] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 917.033345] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 917.033110] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 919.966871] Lustre: *** cfs_fail_loc=1505, val=0*** [ 926.642906] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 00:29:30 (1789446570) [ 927.848258] Lustre: 26252:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 927.855720] Lustre: 26252:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 643 previous similar messages [ 927.860839] Lustre: 26252:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 927.869657] Lustre: 26252:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 927.873829] Lustre: 26252:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 927.877314] Lustre: 26252:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 927.879883] Lustre: 26252:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 927.884289] Lustre: 26252:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 927.889662] Lustre: 26252:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 927.893817] Lustre: 26252:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 927.898903] Lustre: 26252:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 927.904105] Lustre: 26252:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 932.653629] Lustre: *** cfs_fail_loc=1603, val=0*** [ 939.107807] Lustre: Failing over lustre-MDT0000 [ 939.429623] Lustre: server umount lustre-MDT0000 complete [ 942.562971] 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 [ 942.564684] LustreError: 26257:0:(ldlm_lib.c:1199: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. [ 942.581393] Lustre: Skipped 5 previous similar messages [ 942.601394] LustreError: 26257:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 14 previous similar messages [ 951.595310] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 951.783863] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 952.505618] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 957.411556] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 957.418325] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 957.438690] Lustre: Skipped 3 previous similar messages [ 957.496394] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 957.557320] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 957.562415] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 958.406379] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 969.152860] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 00:30:12 (1789446612) [ 976.169718] Lustre: *** cfs_fail_loc=1604, val=0*** [ 985.176815] Lustre: Failing over lustre-MDT0000 [ 985.451801] Lustre: server umount lustre-MDT0000 complete [ 988.130394] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 988.139702] 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 [ 988.156802] Lustre: Skipped 3 previous similar messages [ 996.622920] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 996.702985] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 997.021696] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1001.281465] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1001.960082] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1001.964665] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1001.974164] Lustre: Skipped 3 previous similar messages [ 1001.994024] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1002.052207] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 1002.060285] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 1012.118778] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 00:30:55 (1789446655) [ 1019.179146] Lustre: *** cfs_fail_loc=1605, val=0*** [ 1026.921772] Lustre: Failing over lustre-MDT0000 [ 1027.322753] Lustre: server umount lustre-MDT0000 complete [ 1027.552961] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1038.980599] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1039.154867] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1039.513457] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1044.679425] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1044.965095] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1045.005221] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1045.011833] Lustre: Skipped 3 previous similar messages [ 1045.048264] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1045.091874] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 1045.101234] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1055.217821] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 00:31:38 (1789446698) [ 1056.916941] Lustre: 26253:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1056.929344] Lustre: 26253:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 968 previous similar messages [ 1056.940967] Lustre: 26253:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1056.945874] Lustre: 26253:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1056.950307] Lustre: 26253:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1056.955011] Lustre: 26253:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1056.959873] Lustre: 26253:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1056.967252] Lustre: 26253:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1056.975532] Lustre: 26253:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1056.980047] Lustre: 26253:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1056.986485] Lustre: 26253:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1057.011797] Lustre: 26253:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1062.716524] Lustre: *** cfs_fail_loc=161d, val=0*** [ 1071.716599] Lustre: Failing over lustre-MDT0000 [ 1074.011657] Lustre: server umount lustre-MDT0000 complete [ 1075.679471] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1075.681218] 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 [ 1075.683191] LustreError: 26253:0:(ldlm_lib.c:1199: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. [ 1075.683203] LustreError: 26253:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 24 previous similar messages [ 1075.755526] Lustre: Skipped 7 previous similar messages [ 1086.115523] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1086.186142] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1086.361708] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1086.367308] Lustre: Skipped 3 previous similar messages [ 1086.402755] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1090.620669] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1091.571800] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1091.588773] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1091.588781] Lustre: Skipped 3 previous similar messages [ 1091.631947] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1091.721090] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1091.726293] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 1101.170551] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 00:32:23 (1789446743) [ 1104.324916] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1115.887249] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 00:32:39 (1789446759) [ 1123.769358] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1124.992678] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1140.014678] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 00:33:03 (1789446783) [ 1176.262511] Lustre: Failing over lustre-MDT0000 [ 1176.465849] Lustre: server umount lustre-MDT0000 complete [ 1178.611802] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1182.998646] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1193.951909] Lustre: 16387:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789446822/real 1789446822] req@ffff962f7de2d880 x1876370198869376/t0(0) o400->MGC192.168.202.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789446838 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1193.981569] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1194.162125] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1207.543485] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1207.593123] Lustre: lustre-MDT0000: reset Object Index mappings [ 1220.933184] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1226.012876] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1226.211230] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1226.224946] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1226.228633] Lustre: Skipped 3 previous similar messages [ 1226.260504] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1226.298208] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1226.305530] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1230.777234] LustreError: 42923:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1230.842014] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1240.762328] Lustre: Failing over lustre-MDT0000 [ 1241.426949] Lustre: server umount lustre-MDT0000 complete [ 1241.567669] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1241.580958] 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 [ 1241.630825] Lustre: Skipped 6 previous similar messages [ 1256.061134] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1260.870734] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1262.108555] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1262.108618] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1264.211642] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1272.625614] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 00:35:15 (1789446915) [ 1276.492568] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1290.574007] Lustre: Failing over lustre-MDT0000 [ 1291.002410] Lustre: server umount lustre-MDT0000 complete [ 1292.777974] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1297.385576] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1308.127324] Lustre: 16387:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789446936/real 1789446936] req@ffff962f7f16ed80 x1876370198971904/t0(0) o400->MGC192.168.202.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789446952 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1308.273703] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1320.475574] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1320.491639] Lustre: lustre-MDT0000: reset Object Index mappings [ 1333.728350] LustreError: 30875:0:(ldlm_lib.c:1199: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. [ 1333.730041] LustreError: 16386:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff962f7e22d500 x1876370198983808/t0(0) o250->MGC192.168.202.108@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 [ 1333.739634] LustreError: 30875:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 98 previous similar messages [ 1334.213351] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1334.228712] Lustre: Skipped 1 previous similar message [ 1338.787972] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1339.361523] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1339.368339] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1339.368965] Lustre: Skipped 1 previous similar message [ 1339.378949] Lustre: Skipped 7 previous similar messages [ 1339.395336] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1339.401982] Lustre: Skipped 1 previous similar message [ 1339.446690] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1339.450592] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1342.646307] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1342.647944] Lustre: Skipped 3 previous similar messages [ 1354.904317] Lustre: Failing over lustre-MDT0000 [ 1355.159219] Lustre: server umount lustre-MDT0000 complete [ 1359.844305] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1366.675798] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1366.755644] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1366.761587] LustreError: Skipped 2 previous similar messages [ 1366.963426] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1366.966297] Lustre: Skipped 3 previous similar messages [ 1372.009722] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1372.182085] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1372.183746] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1375.973460] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1375.977676] Lustre: Skipped 84 previous similar messages [ 1384.166693] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 00:37:07 (1789447027) [ 1385.328881] Lustre: 26254:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 1385.354689] Lustre: 26254:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1234 previous similar messages [ 1385.385490] Lustre: 26254:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 1385.404670] Lustre: 26254:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 1385.420557] Lustre: 26254:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1385.426632] Lustre: 26254:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 1385.435975] Lustre: 26254:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1385.441761] Lustre: 26254:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 1385.449789] Lustre: 26254:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1385.456901] Lustre: 26254:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 1385.462372] Lustre: 26254:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1385.480905] Lustre: 26254:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 1392.409811] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1392.421906] Lustre: Skipped 7 previous similar messages [ 1415.175436] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 00:37:38 (1789447058) [ 1422.951736] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1422.958277] Lustre: Skipped 9 previous similar messages [ 1450.935214] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 00:38:13 (1789447093) [ 1462.487791] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1462.493901] Lustre: Skipped 13 previous similar messages [ 1468.407207] Lustre: Failing over lustre-MDT0000 [ 1470.669631] Lustre: server umount lustre-MDT0000 complete [ 1480.685831] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1481.094514] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1481.097162] Lustre: Skipped 1 previous similar message [ 1486.310234] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1486.326140] Lustre: Skipped 1 previous similar message [ 1486.333107] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1486.355688] Lustre: Skipped 7 previous similar messages [ 1486.390589] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1486.403785] Lustre: Skipped 1 previous similar message [ 1486.533315] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:853 to 0x280000401:897) [ 1486.535463] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:854 to 0x2c0000401:897) [ 1486.628546] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1501.601765] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 00:39:04 (1789447144) [ 1517.407688] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 1536.141267] Lustre: 52946:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1562.810905] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1566.921874] Lustre: 54083:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1573.167901] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1573.174709] Lustre: Skipped 81 previous similar messages [ 1576.157495] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1577.183725] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1578.207193] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1580.255792] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1580.257790] Lustre: Skipped 1 previous similar message [ 1581.643558] Lustre: Failing over lustre-MDT0000 [ 1582.107987] Lustre: server umount lustre-MDT0000 complete [ 1583.584573] 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 [ 1583.608425] Lustre: Skipped 15 previous similar messages [ 1592.924616] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1598.731652] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1599.074213] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:946 to 0x280000401:961) [ 1599.074804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 1609.815785] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 00:40:52 (1789447252) [ 1614.326157] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1614.328979] Lustre: Skipped 3 previous similar messages [ 1614.374241] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1614.389085] LustreError: Skipped 1 previous similar message [ 1619.431236] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1619.456552] Lustre: Skipped 5 previous similar messages [ 1620.001786] Lustre: server umount lustre-MDT0000 complete [ 1623.950469] LustreError: 26240:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789447268 with bad export cookie 14699189726451983704 [ 1623.961738] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1623.965224] LustreError: 26240:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1623.976634] LustreError: Skipped 2 previous similar messages [ 1624.243755] Lustre: server umount lustre-MDT0001 complete [ 1638.655486] Lustre: server umount lustre-OST0000 complete [ 1639.887084] Lustre: 16387:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789447268/real 1789447268] req@ffff962f7f380380 x1876370199316096/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789447284 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1642.379672] Lustre: server umount lustre-OST0001 complete [ 1651.139898] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 1659.600890] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 1705.034268] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 1715.057380] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1715.282162] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1715.313962] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1715.419208] Lustre: lustre-MDT0000: new disk, initializing [ 1715.507909] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1720.917261] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1733.493744] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1733.654838] Lustre: 59144:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1733.698140] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1733.705359] Lustre: Skipped 1 previous similar message [ 1733.809994] Lustre: lustre-MDT0001: new disk, initializing [ 1734.008584] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1734.024068] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1739.781512] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1745.001834] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1751.720614] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1751.926041] Lustre: lustre-OST0000: new disk, initializing [ 1751.933615] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1751.939698] Lustre: 60776:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1753.050647] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1753.065948] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1753.208012] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1758.568139] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1769.303791] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1769.461134] Lustre: lustre-OST0001: new disk, initializing [ 1769.463879] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1769.468399] Lustre: 61647:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1771.090479] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1771.105268] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1771.169185] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1776.849289] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1788.744088] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1793.356703] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1802.943576] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1803.923960] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1803.926553] Lustre: Skipped 19 previous similar messages [ 1807.822931] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1807.825576] Lustre: Skipped 5 previous similar messages [ 1823.697893] Lustre: Failing over lustre-MDT0000 [ 1824.029681] Lustre: server umount lustre-MDT0000 complete [ 1832.305314] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1832.608397] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1832.614181] Lustre: Skipped 1 previous similar message [ 1836.936667] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1838.052895] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1838.058915] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1838.064871] Lustre: Skipped 1 previous similar message [ 1838.078164] Lustre: Skipped 7 previous similar messages [ 1838.094076] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1838.102383] Lustre: Skipped 1 previous similar message [ 1838.130253] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1838.137575] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1838.137867] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1845.598617] Lustre: Failing over lustre-MDT0000 [ 1845.797298] Lustre: server umount lustre-MDT0000 complete [ 1848.288406] LustreError: 59152:0:(ldlm_lib.c:1199: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. [ 1848.311376] LustreError: 59152:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 36 previous similar messages [ 1855.058064] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1860.651709] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1860.659576] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1860.659977] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1860.890303] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1866.803570] Lustre: Failing over lustre-MDT0000 [ 1867.101841] Lustre: server umount lustre-MDT0000 complete [ 1870.816635] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1870.826482] LustreError: Skipped 2 previous similar messages [ 1875.856768] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1881.007503] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1881.668122] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1881.674526] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1886.304381] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1886.308662] Lustre: Skipped 1 previous similar message [ 1899.007781] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 00:45:42 (1789447542) [ 1915.737736] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 1935.304182] Lustre: 68601:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1957.547526] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1961.342864] Lustre: 69737:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1968.984601] Lustre: 59152:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1968.992666] Lustre: 59152:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2707 previous similar messages [ 1968.999933] Lustre: 59152:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1969.003445] Lustre: 59152:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2707 previous similar messages [ 1969.007420] Lustre: 59152:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1969.012260] Lustre: 59152:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2707 previous similar messages [ 1969.017423] Lustre: 59152:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1969.024360] Lustre: 59152:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2707 previous similar messages [ 1969.029566] Lustre: 59152:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1969.035141] Lustre: 59152:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2707 previous similar messages [ 1969.041088] Lustre: 59152:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1969.045706] Lustre: 59152:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2707 previous similar messages [ 2064.307247] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 00:48:27 (1789447707) [ 2114.338430] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2114.340143] Lustre: Skipped 4 previous similar messages [ 2139.466275] Lustre: *** cfs_fail_loc=160c, val=0*** [ 2139.472014] Lustre: Skipped 7 previous similar messages [ 2177.177953] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 00:50:20 (1789447820) [ 2216.523852] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2217.568371] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2217.572636] Lustre: Skipped 71 previous similar messages [ 2219.611751] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2219.613340] Lustre: Skipped 111 previous similar messages [ 2223.624422] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2223.627632] Lustre: Skipped 249 previous similar messages [ 2231.624971] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2231.626896] Lustre: Skipped 419 previous similar messages [ 2247.631763] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2247.635306] Lustre: Skipped 942 previous similar messages [ 2278.853751] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2278.859270] Lustre: Skipped 2599 previous similar messages [ 2501.057935] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 00:55:44 (1789448144) [ 2640.215887] Lustre: 62176:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 2640.228135] Lustre: 62176:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 36832 previous similar messages [ 2640.243623] Lustre: 62176:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2640.254031] Lustre: 62176:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2640.270576] Lustre: 62176:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2640.287262] Lustre: 62176:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2640.295326] Lustre: 62176:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2640.310781] Lustre: 62176:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2640.320584] Lustre: 62176:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2640.331627] Lustre: 62176:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2640.351804] Lustre: 62176:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2640.359758] Lustre: 62176:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2649.568176] 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 [ 2649.571217] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2649.581296] Lustre: Skipped 20 previous similar messages [ 2649.597472] Lustre: Skipped 3 previous similar messages [ 2653.167034] Lustre: server umount lustre-MDT0000 complete [ 2654.688499] LustreError: 65552:0:(ldlm_lib.c:1199: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. [ 2654.705463] LustreError: 65552:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 15 previous similar messages [ 2656.581289] LustreError: 59137:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789448300 with bad export cookie 14699189726452002793 [ 2656.582663] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2656.589027] LustreError: 59137:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2656.602826] LustreError: Skipped 3 previous similar messages [ 2656.862267] Lustre: server umount lustre-MDT0001 complete [ 2671.370216] Lustre: server umount lustre-OST0000 complete [ 2685.542418] Lustre: server umount lustre-OST0001 complete [ 2693.444901] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2701.401273] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2716.960563] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2722.079861] LustreError: 75223:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.108@tcp: failed processing log, type 4: rc = -110 [ 2747.807379] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2747.815400] Lustre: Skipped 9 previous similar messages [ 2753.551606] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2756.922517] Lustre: 75807:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2756.940966] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2759.971412] Lustre: 75807:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2768.990746] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 01:00:12 (1789448412) [ 2782.966378] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 2794.501199] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2795.225417] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2799.979942] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2808.915288] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2813.385734] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2816.525802] Lustre: 78471:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2831.251877] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2831.429636] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2831.433236] Lustre: Skipped 2 previous similar messages [ 2836.485440] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2837.913536] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2845.690675] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2848.993442] Lustre: 79984:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2853.469182] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2860.722623] Lustre: Failing over lustre-OST0000 [ 2860.840288] Lustre: server umount lustre-OST0000 complete [ 2871.169537] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2871.366192] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2871.371908] Lustre: Skipped 2 previous similar messages [ 2872.613103] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2872.620318] Lustre: Skipped 2 previous similar messages [ 2872.638416] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2872.642127] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2872.642524] Lustre: *** cfs_fail_loc=215, val=0*** [ 2872.646807] Lustre: Skipped 2 previous similar messages [ 2872.650392] Lustre: Skipped 11 previous similar messages [ 2877.527171] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2877.921322] Lustre: *** cfs_fail_loc=215, val=0*** [ 2877.926938] Lustre: Skipped 2 previous similar messages [ 2880.889802] Lustre: 81387:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2880.937517] Lustre: 81387:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2883.044102] Lustre: *** cfs_fail_loc=215, val=0*** [ 2883.046821] Lustre: Skipped 1 previous similar message [ 2883.546096] Lustre: Failing over lustre-OST0000 [ 2883.656612] Lustre: server umount lustre-OST0000 complete [ 2891.327877] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2893.193434] Lustre: *** cfs_fail_loc=215, val=0*** [ 2896.334942] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2898.399780] Lustre: *** cfs_fail_loc=215, val=0*** [ 2898.407233] Lustre: Skipped 1 previous similar message [ 2901.472767] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2901.486864] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2907.104901] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2907.109915] Lustre: Skipped 6 previous similar messages [ 2907.477956] Lustre: server umount lustre-MDT0000 complete [ 2910.611876] LustreError: 75231:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789448554 with bad export cookie 14699189726453562043 [ 2910.627647] LustreError: 75231:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 2911.017602] Lustre: server umount lustre-MDT0001 complete [ 2925.261488] Lustre: server umount lustre-OST0000 complete [ 2928.353547] Lustre: 16390:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789448556/real 1789448556] req@ffff962e4774bb80 x1876370203175936/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789448572 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2929.117514] Lustre: server umount lustre-OST0001 complete [ 2938.522386] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 01:03:01 (1789448581) [ 2953.971320] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 2964.545732] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2965.074225] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2965.081922] Lustre: Skipped 2 previous similar messages [ 2969.761781] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2978.845024] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2983.248968] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2985.841853] Lustre: 85769:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2992.759769] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2999.618807] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3008.408252] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3010.674711] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 3010.758095] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 3014.903679] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3021.543964] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3024.787649] Lustre: 87637:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3054.627672] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 01:04:57 (1789448697) [ 3071.510490] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 01:05:14 (1789448714) [ 3072.902462] Lustre: *** cfs_fail_loc=160f, val=0*** [ 3084.821475] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 01:05:28 (1789448728) [ 3088.705957] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3088.708084] Lustre: Skipped 7 previous similar messages [ 3138.021427] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3143.766964] Lustre: server umount lustre-MDT0000 complete [ 3148.113076] LustreError: 90314:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789448792 with bad export cookie 14699189726453570541 [ 3148.129063] LustreError: 90314:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 3148.677934] Lustre: server umount lustre-MDT0001 complete [ 3163.399205] Lustre: server umount lustre-OST0000 complete [ 3165.664900] Lustre: 16390:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789448793/real 1789448793] req@ffff962e4e5bc380 x1876370203401600/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789448809 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3166.614705] Lustre: server umount lustre-OST0001 complete [ 3180.819653] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 3190.730895] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3195.614715] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3204.827261] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3209.391737] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3212.326744] Lustre: 93501:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3218.081199] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3224.291282] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3230.758983] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3232.460280] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3232.668870] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3232.676693] Lustre: Skipped 6 previous similar messages [ 3237.800055] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 3237.801711] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 3237.808613] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 3238.674664] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3246.297906] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3249.825911] Lustre: 95372:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3256.805732] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 01:08:20 (1789448900) [ 3258.689550] Lustre: 92359:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3258.701193] Lustre: 92359:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1365 previous similar messages [ 3258.707190] Lustre: 92359:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3258.714018] Lustre: 92359:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1365 previous similar messages [ 3258.722995] Lustre: 92359:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3258.730070] Lustre: 92359:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1365 previous similar messages [ 3258.737792] Lustre: 92359:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3258.746059] Lustre: 92359:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1365 previous similar messages [ 3258.755070] Lustre: 92359:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3258.764608] Lustre: 92359:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1365 previous similar messages [ 3258.775353] Lustre: 92359:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3258.781762] Lustre: 92359:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1365 previous similar messages [ 3262.170582] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3262.176909] Lustre: Skipped 63 previous similar messages [ 3281.891670] 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 [ 3281.906947] Lustre: Skipped 15 previous similar messages [ 3281.911305] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3281.915352] Lustre: Skipped 4 previous similar messages [ 3287.524643] Lustre: server umount lustre-MDT0000 complete [ 3289.058755] LustreError: 96060:0:(ldlm_lib.c:1199: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. [ 3289.075426] LustreError: 96060:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 42 previous similar messages [ 3291.563094] LustreError: 92345:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789448935 with bad export cookie 14699189726453598940 [ 3291.569724] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3291.586178] LustreError: 92345:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3291.596940] LustreError: Skipped 2 previous similar messages [ 3291.870688] Lustre: server umount lustre-MDT0001 complete [ 3306.917490] Lustre: server umount lustre-OST0000 complete [ 3310.047081] Lustre: 16389:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789448938/real 1789448938] req@ffff962e4c429880 x1876370203526400/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789448954 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3310.371613] Lustre: server umount lustre-OST0001 complete [ 3326.610350] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 3336.936223] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3341.888130] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3350.212275] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3355.019751] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3357.982970] Lustre: 99403:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3365.278947] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3371.267783] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3374.897470] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3378.852707] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3382.193139] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3382.199663] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3382.204890] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3385.329383] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3392.458700] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3401.372635] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 01:10:45 (1789449045) [ 3404.354184] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3404.355877] Lustre: Skipped 63 previous similar messages [ 3404.459266] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3413.449629] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 01:10:57 (1789449057) [ 3416.600054] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3416.688088] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3416.694116] Lustre: Skipped 2 previous similar messages [ 3428.058641] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 01:11:11 (1789449071) [ 3429.438040] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3431.211732] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 01:11:14 (1789449074) [ 3436.992660] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3436.996609] LustreError: 98274:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f16 failed: rc = -5 [ 3500.003511] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3500.009261] Lustre: Skipped 6 previous similar messages [ 3505.518269] Lustre: server umount lustre-MDT0000 complete [ 3512.814104] LustreError: 98245:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789449157 with bad export cookie 14699189726453613668 [ 3512.827684] LustreError: 98245:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3513.145829] Lustre: server umount lustre-MDT0001 complete [ 3529.503230] Lustre: 16387:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789449157/real 1789449157] req@ffff962e486d1500 x1876370204159360/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789449173 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3530.690732] Lustre: server umount lustre-OST0000 complete [ 3534.815875] Lustre: 16388:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789449162/real 1789449162] req@ffff962e52815880 x1876370204159872/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789449178 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3534.836275] Lustre: 16388:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3538.759792] Lustre: server umount lustre-OST0001 complete [ 3555.311406] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing unload_modules_local [ 3558.133899] Key type lgssc unregistered [ 3558.473658] LNet: 105111:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3558.491847] LNetError: 105111:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3558.521080] LNet: Removed LNI 192.168.202.108@tcp [ 3560.028586] Key type .llcrypt unregistered [ 3560.031300] Key type ._llcrypt unregistered [ 3583.969413] Key type ._llcrypt registered [ 3583.970954] Key type .llcrypt registered [ 3584.076217] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 3595.377410] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 3596.274799] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3596.402462] alg: No test for adler32 (adler32-zlib) [ 3597.585531] Lustre: Lustre: Build Version: 2.17.58_39_ge07ba0b [ 3597.803874] LNet: Added LNI 192.168.202.108@tcp [8/256/0/180] [ 3599.455244] Key type lgssc registered [ 3600.334672] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3648.212785] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 3660.161636] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3660.199337] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3661.386287] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3661.399307] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3661.450367] Lustre: lustre-MDT0000: new disk, initializing [ 3661.491259] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3661.501197] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3665.413744] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3678.110129] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3678.200531] Lustre: 109543:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3678.224926] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3678.228160] Lustre: Skipped 1 previous similar message [ 3678.299163] Lustre: lustre-MDT0001: new disk, initializing [ 3678.362150] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3678.400399] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3678.407980] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3682.908716] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3687.766436] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3697.159634] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3697.387828] Lustre: lustre-OST0000: new disk, initializing [ 3697.391882] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3697.401050] Lustre: 111478:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3697.481492] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3701.273171] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3701.285326] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3701.378779] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3703.611888] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3715.980701] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3716.107728] Lustre: lustre-OST0001: new disk, initializing [ 3716.111574] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3716.115914] Lustre: 112503:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3716.165961] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3722.464399] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3726.350056] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3726.358505] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3726.430589] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3733.579578] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3744.892740] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3750.553887] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 01:16:33 (1789449393) === [ 3757.347172] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 01:16:40 (1789449400) [ 3757.666663] Lustre: 109548:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3757.673706] Lustre: 109548:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3757.678234] Lustre: 109548:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3757.686408] Lustre: 109548:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3757.695114] Lustre: 109548:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3757.699295] Lustre: 109548:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3758.170293] Lustre: 113021:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 3758.177543] Lustre: 113021:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 48 previous similar messages [ 3758.182274] Lustre: 113021:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3758.185454] Lustre: 113021:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 3758.190900] Lustre: 113021:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3758.196041] Lustre: 113021:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 3758.200854] Lustre: 113021:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3758.204990] Lustre: 113021:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 3758.211210] Lustre: 113021:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3758.215735] Lustre: 113021:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 3758.221548] Lustre: 113021:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3758.226673] Lustre: 113021:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 3760.001240] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3769.588108] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 01:16:53 (1789449413) [ 3770.887970] Lustre: 109549:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3770.893312] Lustre: 109549:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 260 previous similar messages [ 3770.897118] Lustre: 109549:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 3770.900159] Lustre: 109549:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 260 previous similar messages [ 3770.903340] Lustre: 109549:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3770.906263] Lustre: 109549:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 260 previous similar messages [ 3770.909032] Lustre: 109549:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3770.911957] Lustre: 109549:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 260 previous similar messages [ 3770.914650] Lustre: 109549:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3770.917670] Lustre: 109549:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 260 previous similar messages [ 3770.920937] Lustre: 109549:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3770.924106] Lustre: 109549:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 260 previous similar messages [ 3771.774591] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3775.981232] Lustre: 111468:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3775.991631] Lustre: 111468:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3776.006222] Lustre: 111468:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3776.022285] Lustre: 111468:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3776.033161] Lustre: 111468:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3776.047832] Lustre: 111468:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3776.062428] Lustre: 111468:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3776.076018] Lustre: 111468:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3776.101247] Lustre: 111468:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3776.108534] Lustre: 111468:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3776.115520] Lustre: 111468:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3776.137377] Lustre: 111468:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3782.404310] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 01:17:06 (1789449426) [ 3782.778313] Lustre: 113021:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3782.786919] Lustre: 113021:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1 previous similar message [ 3782.792499] Lustre: 113021:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3782.800656] Lustre: 113021:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3782.806536] Lustre: 113021:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3782.813682] Lustre: 113021:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3782.819704] Lustre: 113021:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3782.826770] Lustre: 113021:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3782.834754] Lustre: 113021:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3782.842184] Lustre: 113021:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3782.848267] Lustre: 113021:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3782.853513] Lustre: 113021:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3784.851152] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3784.856596] Lustre: Skipped 1 previous similar message [ 3786.106902] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3786.109774] Lustre: Skipped 1 previous similar message [ 3803.280383] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3804.950475] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 01:17:28 (1789449448) [ 3805.606410] Lustre: 111704:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3805.614110] Lustre: 111704:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3805.620704] Lustre: 111704:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3805.628244] Lustre: 111704:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3805.635708] Lustre: 111704:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3805.643960] Lustre: 111704:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3805.651726] Lustre: 111704:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3805.664400] Lustre: 111704:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3805.673894] Lustre: 111704:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3805.684940] Lustre: 111704:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3805.696684] Lustre: 111704:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3805.716500] Lustre: 111704:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3808.360117] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3808.443120] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3811.055722] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3811.057689] Lustre: Skipped 3 previous similar messages [ 3830.053645] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 01:17:53 (1789449473) [ 3830.501631] Lustre: 109548:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3830.511722] Lustre: 109548:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 24 previous similar messages [ 3830.520722] Lustre: 109548:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3830.528983] Lustre: 109548:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3830.535262] Lustre: 109548:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3830.543253] Lustre: 109548:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3830.554087] Lustre: 109548:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3830.562240] Lustre: 109548:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3830.574580] Lustre: 109548:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3830.585697] Lustre: 109548:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3830.597190] Lustre: 109548:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3830.602753] Lustre: 109548:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3832.076524] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3832.078810] Lustre: Skipped 5 previous similar messages [ 3868.128849] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3868.135133] 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 [ 3868.158716] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3868.682897] Lustre: server umount lustre-MDT0000 complete [ 3869.666341] 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 [ 3872.596267] LustreError: 116308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789449516 with bad export cookie 1128030079609037820 [ 3872.608114] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3872.619916] LustreError: 116308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3873.314788] Lustre: server umount lustre-MDT0001 complete [ 3888.763617] Lustre: server umount lustre-OST0000 complete [ 3891.551269] Lustre: 106702:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789449519/real 1789449519] req@ffff962e49262680 x1876373528584576/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789449535 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3891.605381] 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 [ 3891.624533] Lustre: Skipped 2 previous similar messages [ 3892.917163] Lustre: server umount lustre-OST0001 complete [ 3909.648854] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 3921.967429] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3922.477301] LustreError: 118214:0:(ldlm_lib.c:1199: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. [ 3922.495381] LustreError: 118214:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 3922.600504] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3927.938619] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3928.033575] LustreError: 118215:0:(ldlm_lib.c:1199: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. [ 3932.133257] LustreError: 118214:0:(ldlm_lib.c:1199: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. [ 3937.258884] LustreError: 118215:0:(ldlm_lib.c:1199: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. [ 3937.304366] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3937.837552] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3941.752516] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3944.733096] Lustre: 119353:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3953.077040] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3960.141842] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3962.658389] LustreError: 119706:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: 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. [ 3962.667888] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3967.789808] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3969.420223] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3969.745612] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3969.754251] Lustre: Skipped 1 previous similar message [ 3975.151109] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3975.175386] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3976.552936] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3985.199484] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3988.770652] Lustre: 121224:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4003.698804] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 01:20:46 (1789449646) [ 4004.218638] Lustre: 118211:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 4004.227091] Lustre: 118211:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4004.242309] Lustre: 118211:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4004.261086] Lustre: 118211:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4004.274323] Lustre: 118211:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4004.290961] Lustre: 118211:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4004.301919] Lustre: 118211:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 4004.313715] Lustre: 118211:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4004.331259] Lustre: 118211:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 4004.344378] Lustre: 118211:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4004.353693] Lustre: 118211:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4004.366144] Lustre: 118211:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4007.045459] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4007.053613] Lustre: Skipped 3 previous similar messages [ 4041.704208] 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 [ 4041.707602] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4041.743743] Lustre: Skipped 3 previous similar messages [ 4041.754517] Lustre: Skipped 2 previous similar messages [ 4046.818120] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4046.824383] Lustre: Skipped 4 previous similar messages [ 4047.294211] Lustre: server umount lustre-MDT0000 complete [ 4051.047553] LustreError: 118195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789449695 with bad export cookie 1128030079609053080 [ 4051.060794] LustreError: 118195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4051.064231] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4051.427145] Lustre: server umount lustre-MDT0001 complete [ 4065.533615] Lustre: server umount lustre-OST0000 complete [ 4068.326962] Lustre: 106703:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789449696/real 1789449696] req@ffff962e524cd880 x1876373528662144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789449712 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4068.366450] 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 [ 4070.564536] Lustre: server umount lustre-OST0001 complete [ 4090.325035] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 4103.262613] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4103.744490] LustreError: 123793:0:(ldlm_lib.c:1199: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. [ 4103.780711] LustreError: 123793:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 4103.895058] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4108.841791] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4118.433035] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4123.546384] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4126.126887] Lustre: 124933:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4131.795401] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4138.743743] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4144.302826] LustreError: 125284:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: 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. [ 4144.329976] LustreError: 125284:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 4144.340734] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 4148.100985] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4149.307786] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 4149.311159] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 4149.404279] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 4154.843615] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4162.525772] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4166.472849] Lustre: 126801:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4173.057728] Lustre: 123793:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 4173.077323] Lustre: 123793:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4173.089558] Lustre: 123793:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4173.108072] Lustre: 123793:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4173.121596] Lustre: 123793:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 4173.126357] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4173.129976] Lustre: 123793:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4173.130021] Lustre: 123793:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 4173.130026] Lustre: 123793:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4173.130035] Lustre: 123793:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 4173.130039] Lustre: 123793:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4173.130045] Lustre: 123793:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4173.130048] Lustre: 123793:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4173.213243] Lustre: Skipped 1 previous similar message [ 4200.184105] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 01:24:03 (1789449843) [ 4203.667399] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4203.684111] Lustre: Skipped 3 previous similar messages [ 4212.267224] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4232.593808] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 01:24:35 (1789449875) [ 4234.658880] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4249.518206] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 01:24:52 (1789449892) [ 4255.173239] Lustre: *** cfs_fail_loc=162f, val=0*** [ 4255.182321] Lustre: Skipped 9 previous similar messages [ 4278.508666] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 01:25:21 (1789449921) [ 4293.587457] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 01:25:35 (1789449935) [ 4297.820246] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4297.874313] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4297.882826] Lustre: Skipped 3 previous similar messages [ 4303.813465] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.8@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:202 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 4304.967564] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.8@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 4315.571873] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 01:25:58 (1789449958) [ 4316.079258] Lustre: 125308:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4316.087301] Lustre: 125308:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 104 previous similar messages [ 4316.091867] Lustre: 125308:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4316.096238] Lustre: 125308:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 4316.100822] Lustre: 125308:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4316.105557] Lustre: 125308:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 4316.110065] Lustre: 125308:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4316.115107] Lustre: 125308:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 4316.120751] Lustre: 125308:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4316.125037] Lustre: 125308:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 4316.129810] Lustre: 125308:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4316.134142] Lustre: 125308:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 4319.947928] Lustre: *** cfs_fail_loc=161a, val=1*** [ 4319.953926] Lustre: Skipped 5 previous similar messages [ 4347.032669] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 01:26:30 (1789449990) [ 4355.310424] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 01:26:38 (1789449998) [ 4368.753868] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 01:26:52 (1789450012) [ 4371.237629] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4371.257389] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4371.271330] Lustre: Skipped 1 previous similar message [ 4382.865284] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 01:27:06 (1789450026) [ 4384.967113] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4384.971728] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4396.565652] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 01:27:19 (1789450039) [ 4398.590731] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4412.352499] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4413.795172] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 01:27:37 (1789450057) [ 4420.061299] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4420.063266] Lustre: Skipped 1 previous similar message [ 4423.111693] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4443.058878] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 01:28:06 (1789450086) [ 4445.280381] Lustre: Failing over lustre-MDT0000 [ 4445.798598] Lustre: server umount lustre-MDT0000 complete [ 4446.184119] 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 [ 4446.186210] LustreError: 126938:0:(ldlm_lib.c:1199: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. [ 4446.204143] Lustre: Skipped 2 previous similar messages [ 4446.248080] LustreError: 126938:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 4 previous similar messages [ 4456.886797] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4456.977429] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4457.190049] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4457.192475] Lustre: Skipped 3 previous similar messages [ 4457.231190] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4461.579220] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4462.607901] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4462.645666] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4462.725850] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4462.729453] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4462.786564] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4465.162953] LustreError: 123789:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4477.663695] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 01:28:41 (1789450121) [ 4479.408340] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4479.519681] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4479.521713] Lustre: Skipped 1 previous similar message [ 4493.565632] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 01:28:55 (1789450135) [ 4496.257562] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4510.115244] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 01:29:13 (1789450153) [ 4512.187249] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4524.986551] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 01:29:28 (1789450168) [ 4539.093665] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 01:29:42 (1789450182) [ 4541.362461] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4541.366933] Lustre: Skipped 1 previous similar message [ 4553.369407] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 01:29:56 (1789450196) [ 4566.377654] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 01:30:09 (1789450209) [ 4572.036694] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4572.039628] Lustre: Skipped 1 previous similar message [ 4588.921620] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 01:30:32 (1789450232) [ 4590.358819] Lustre: 123788:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4590.372873] Lustre: 123788:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 518 previous similar messages [ 4590.384029] Lustre: 123788:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4590.400693] Lustre: 123788:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 518 previous similar messages [ 4590.414147] Lustre: 123788:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4590.424727] Lustre: 123788:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 518 previous similar messages [ 4590.434499] Lustre: 123788:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4590.456590] Lustre: 123788:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 518 previous similar messages [ 4590.464164] Lustre: 123788:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4590.477128] Lustre: 123788:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 518 previous similar messages [ 4590.495585] Lustre: 123788:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4590.503615] Lustre: 123788:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 518 previous similar messages [ 4592.453063] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4592.461395] Lustre: Skipped 4 previous similar messages [ 4607.120443] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 01:30:50 (1789450250) [ 4640.712912] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 01:31:23 (1789450283) [ 4645.127763] LustreError: 125308:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4653.111631] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 01:31:36 (1789450296) [ 4657.110217] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4657.123395] Lustre: Skipped 2 previous similar messages [ 4675.016213] Lustre: Failing over lustre-MDT0000 [ 4675.544020] Lustre: server umount lustre-MDT0000 complete [ 4675.555547] 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 [ 4675.570240] Lustre: Skipped 3 previous similar messages [ 4675.574280] LustreError: 127066:0:(ldlm_lib.c:1199: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. [ 4675.611996] LustreError: 127066:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 13 previous similar messages [ 4687.751185] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4687.883797] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4688.175972] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4688.223176] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4693.326490] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4693.484353] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4693.489788] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4693.512757] Lustre: Skipped 3 previous similar messages [ 4693.542843] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4693.639418] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 4693.642248] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 4708.218570] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 01:32:31 (1789450351) [ 4722.958721] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 01:32:46 (1789450366) [ 4738.115967] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 01:33:01 (1789450381) [ 4739.672395] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4739.677636] Lustre: Skipped 1 previous similar message [ 4754.569225] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 01:33:17 (1789450397) [ 4761.669432] Lustre: Failing over lustre-MDT0000 [ 4764.156583] Lustre: server umount lustre-MDT0000 complete [ 4765.152312] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4765.154744] 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 [ 4765.207912] Lustre: Skipped 3 previous similar messages [ 4774.281673] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4774.417318] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4774.862831] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4780.004789] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4780.014426] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4780.038714] Lustre: Skipped 3 previous similar messages [ 4780.064741] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4780.131546] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 4780.131865] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 4780.302743] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4793.397701] Lustre: Failing over lustre-MDT0000 [ 4793.917600] Lustre: server umount lustre-MDT0000 complete [ 4795.365450] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4803.596405] LustreError: 126938:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4803.653607] LustreError: 126938:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 25 previous similar messages [ 4804.915433] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4805.241545] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4805.606768] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4808.724106] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4810.750142] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4810.789274] Lustre: Skipped 3 previous similar messages [ 4810.852389] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4810.957893] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 4810.959159] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 4811.767984] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4821.405334] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 01:34:24 (1789450464) [ 4835.697187] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 01:34:38 (1789450478) [ 4851.573660] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 01:34:54 (1789450494) [ 4892.016572] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 01:35:35 (1789450535) [ 4909.018600] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 01:35:51 (1789450551) [ 4926.127170] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4929.175117] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4929.197756] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4930.548952] Lustre: Failing over lustre-OST0000 [ 4930.961899] Lustre: server umount lustre-OST0000 complete [ 4932.215672] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4932.234105] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4933.087480] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4933.100503] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4933.128268] Lustre: Skipped 5 previous similar messages [ 4934.840164] LustreError: 148181:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4949.723393] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4950.040465] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4950.046494] Lustre: Skipped 2 previous similar messages [ 4950.052292] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4951.842701] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4951.867234] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4951.871090] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4951.883286] Lustre: Skipped 3 previous similar messages [ 4957.246362] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4967.835312] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 01:36:51 (1789450611) [ 4983.165676] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 5003.142961] Lustre: 150987:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5029.388560] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5033.035539] Lustre: 152122:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5042.662451] LustreError: 152240:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5042.691709] LustreError: 152240:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5045.518054] Lustre: Failing over lustre-MDT0001 [ 5045.720786] LustreError: 152239:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5045.745803] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 5045.765613] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5046.079533] Lustre: server umount lustre-MDT0001 complete [ 5048.742373] LustreError: 152239:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5048.759468] LustreError: 152239:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5061.914082] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5062.293250] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5066.563845] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5067.748930] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5067.753801] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5067.786035] Lustre: Skipped 1 previous similar message [ 5067.820755] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5067.893994] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 5067.896025] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 5075.573245] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 01:38:38 (1789450718) [ 5091.106042] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 5114.136969] Lustre: 154961:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5140.473697] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5145.883646] Lustre: 156098:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5148.453695] Lustre: 138841:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 5148.468110] Lustre: 138841:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1221 previous similar messages [ 5148.497885] Lustre: 138841:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 5148.519742] Lustre: 138841:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1221 previous similar messages [ 5148.538890] Lustre: 138841:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 5148.569527] Lustre: 138841:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1221 previous similar messages [ 5148.582329] Lustre: 138841:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 5148.601773] Lustre: 138841:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1221 previous similar messages [ 5148.625645] Lustre: 138841:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 5148.637673] Lustre: 138841:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1221 previous similar messages [ 5148.655544] Lustre: 138841:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 5148.672596] Lustre: 138841:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1221 previous similar messages [ 5172.731791] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 01:40:15 (1789450815) [ 5174.754421] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 5176.980053] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 01:40:19 (1789450819) [ 5184.589541] Lustre: *** cfs_fail_loc=1631, val=0*** [ 5200.364649] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5200.383707] 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 [ 5200.398249] Lustre: Skipped 4 previous similar messages [ 5200.404568] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5202.498934] Lustre: server umount lustre-MDT0000 complete [ 5205.942608] LustreError: 156722:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789450850 with bad export cookie 1128030079609125908 [ 5205.943497] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5205.948075] LustreError: 156722:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 5205.984459] LustreError: 126938:0:(ldlm_lib.c:1199: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. [ 5205.991546] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5206.002197] LustreError: 126938:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 18 previous similar messages [ 5206.028468] Lustre: Skipped 4 previous similar messages [ 5206.261303] Lustre: server umount lustre-MDT0001 complete [ 5216.271724] Lustre: server umount lustre-OST0000 complete [ 5220.584160] Lustre: server umount lustre-OST0001 complete [ 5243.704307] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 5254.982801] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5259.845686] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5271.071282] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5278.118866] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5282.359826] Lustre: 159995:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5290.975236] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5296.383699] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 5298.375266] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5300.467287] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 5308.617687] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5314.039467] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 5314.051913] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 5315.105893] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5323.902677] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5328.106518] Lustre: 161866:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5340.012455] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 01:43:02 (1789450982) [ 5341.956894] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 5344.198389] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 01:43:07 (1789450987) [ 5346.075853] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 5347.957434] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 01:43:11 (1789450991) [ 5349.648287] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 5351.875525] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 01:43:14 (1789450994) [ 5366.715569] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 01:43:29 (1789451009) [ 5385.669382] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 01:43:48 (1789451028) [ 5404.372911] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 01:44:07 (1789451047) [ 5425.774995] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 01:44:28 (1789451068) [ 5452.883923] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 01:44:55 (1789451095) [ 5488.614681] Lustre: *** cfs_fail_loc=1632, val=0*** [ 5506.863201] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 01:45:49 (1789451149) [ 5511.068877] Lustre: Failing over lustre-MDT0001 [ 5511.560929] Lustre: server umount lustre-MDT0001 complete [ 5512.673380] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 5512.696300] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5512.719919] Lustre: Skipped 5 previous similar messages [ 5521.009138] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5521.528133] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5521.541703] Lustre: Skipped 5 previous similar messages [ 5521.588399] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5521.589877] Lustre: lustre-MDT0001: Aborting client recovery [ 5521.607934] LustreError: 165661:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 5521.610054] Lustre: 165685:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5521.639607] Lustre: 165685:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 32d6e3a2-93d3-4862-8b0d-45539899ddc5@ [ 5521.657789] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 5521.676870] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 5521.695380] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 5521.783967] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:131 to 0x2c0000400:161) [ 5521.793661] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:161) [ 5527.010287] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 5527.042987] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5527.052175] Lustre: Skipped 3 previous similar messages [ 5527.948305] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5532.957023] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 5540.548294] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 5540.954187] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 5550.928800] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 01:46:33 (1789451193) [ 5562.003753] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5565.008716] Lustre: Failing over lustre-MDT0000 [ 5565.545340] Lustre: server umount lustre-MDT0000 complete [ 5567.466173] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5575.712063] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5575.909670] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5576.227853] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5576.230791] Lustre: Skipped 2 previous similar messages [ 5579.274082] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5581.298965] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5581.316570] Lustre: Skipped 1 previous similar message [ 5581.382171] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 5581.458874] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 5581.459050] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5582.115175] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5594.376303] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 01:47:17 (1789451237) [ 5646.917814] Lustre: Failing over lustre-OST0001 [ 5647.314714] Lustre: server umount lustre-OST0001 complete [ 5655.426538] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null) [ 5668.624552] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5668.859449] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 5669.923283] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5670.265550] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5670.275993] Lustre: lustre-OST0001-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5670.289945] Lustre: Skipped 3 previous similar messages [ 5675.578232] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5684.039286] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5684.265326] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5689.604122] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5689.899852] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5697.916845] Lustre: DEBUG MARKER: oleg208-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff94fc4428e800.ost_server_uuid 50 [ 5699.997038] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff94fc4428e800.ost_server_uuid in FULL state after 0 sec [ 5786.082693] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5786.102457] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5790.497736] Lustre: server umount lustre-MDT0000 complete [ 5791.727038] LustreError: 158849:0:(ldlm_lib.c:1199: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. [ 5791.767792] LustreError: 158849:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 45 previous similar messages [ 5800.947396] LustreError: 158834:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789451445 with bad export cookie 1128030079609208690 [ 5800.959426] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5800.963543] LustreError: 158834:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5801.367757] Lustre: server umount lustre-MDT0001 complete [ 5818.207163] Lustre: 106701:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451446/real 1789451446] req@ffff962f50882300 x1876373530531328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451462 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5820.491273] Lustre: server umount lustre-OST0000 complete [ 5821.985566] Lustre: 106703:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451450/real 1789451450] req@ffff962e4bc76a00 x1876373530531584/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451466 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5823.391362] Lustre: 106701:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451451/real 1789451451] req@ffff962e4bc77480 x1876373530531840/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451467 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5828.191835] Lustre: 106703:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451456/real 1789451456] req@ffff962f445fd180 x1876373530532224/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451472 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5830.266911] Lustre: server umount lustre-OST0001 complete [ 5848.064241] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing unload_modules_local [ 5850.304609] Key type lgssc unregistered [ 5850.562176] LNet: 175315:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5850.573576] LNetError: 175315:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5850.584652] LNet: Removed LNI 192.168.202.108@tcp [ 5851.134132] Key type .llcrypt unregistered [ 5851.136969] Key type ._llcrypt unregistered [ 5876.717721] Key type ._llcrypt registered [ 5876.720406] Key type .llcrypt registered [ 5876.878731] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_hostid [ 5898.327576] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 5900.066491] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5900.435947] alg: No test for adler32 (adler32-zlib) [ 5901.520467] Lustre: Lustre: Build Version: 2.17.58_39_ge07ba0b [ 5901.731551] LNet: Added LNI 192.168.202.108@tcp [8/256/0/180] [ 5903.488103] Key type lgssc registered [ 5904.797310] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5970.537107] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing load_modules_local [ 5985.893260] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 5985.954058] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5987.245817] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5987.269891] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5987.337936] Lustre: lustre-MDT0000: new disk, initializing [ 5987.396485] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5987.412722] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5992.194208] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6007.414402] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6007.553797] Lustre: 179769:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 6007.603770] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6007.609709] Lustre: Skipped 1 previous similar message [ 6007.700615] Lustre: lustre-MDT0001: new disk, initializing [ 6007.796677] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6007.825801] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6007.852721] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6015.850709] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6023.164669] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6037.743666] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6038.052661] Lustre: lustre-OST0000: new disk, initializing [ 6038.060906] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6038.066593] Lustre: 181708:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6038.146982] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6043.686862] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6043.704090] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6043.758922] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6045.541162] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6059.528879] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6059.652728] Lustre: lustre-OST0001: new disk, initializing [ 6059.657783] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6059.663874] Lustre: 182736:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6059.744805] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 6067.078973] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6067.762094] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6067.789089] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6067.839203] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6079.671703] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6087.078887] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6092.627670] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 01:55:36 (1789451736) === [ 6094.026642] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5825 sec ========= 01:55:37 (1789451737) [ 6096.036128] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 01:55:39 (1789451739) === [ 6099.776162] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 01:55:42 (1789451742) === [ 6104.034069] 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 [ 6104.040205] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6104.049394] Lustre: Skipped 1 previous similar message [ 6109.154313] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6109.160863] Lustre: Skipped 6 previous similar messages [ 6109.958828] Lustre: server umount lustre-MDT0000 complete [ 6117.698208] LustreError: 181183:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789451761 with bad export cookie 12197766347112913547 [ 6117.712342] LustreError: MGC192.168.202.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6117.724091] LustreError: 181183:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 6118.027929] Lustre: server umount lustre-MDT0001 complete [ 6135.776603] Lustre: 176928:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451763/real 1789451763] req@ffff962e4df0ea00 x1876375943334016/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451779 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6135.812825] 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 [ 6135.827767] Lustre: Skipped 2 previous similar messages [ 6136.968555] Lustre: server umount lustre-OST0000 complete [ 6138.783124] Lustre: 176926:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451766/real 1789451766] req@ffff962e44cdf100 x1876375943334272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451782 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6139.876787] Lustre: 176927:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451768/real 1789451768] req@ffff962e4df0d880 x1876375943334528/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451784 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6142.945912] Lustre: 176926:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789451771/real 1789451771] req@ffff962e44cdfb80 x1876375943334912/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789451787 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6146.806651] Lustre: server umount lustre-OST0001 complete [ 6164.418229] Lustre: DEBUG MARKER: oleg208-server.virtnet: executing unload_modules_local [ 6167.363239] Key type lgssc unregistered [ 6167.743564] LNet: 186211:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6167.752207] LNetError: 186211:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6168.814542] LNet: Removed LNI 192.168.202.108@tcp [ 6170.117531] Key type .llcrypt unregistered [ 6170.122388] Key type ._llcrypt unregistered