[ 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 481000694 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.003129] x2apic enabled [ 0.004006] Switched APIC routing to physical x2apic. [ 0.005014] kvm-guest: setup PV IPIs [ 0.008574] ..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.009019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010011] pid_max: default: 32768 minimum: 301 [ 0.012090] LSM: Security Framework initializing [ 0.014010] Yama: becoming mindful. [ 0.015039] SELinux: Initializing. [ 0.016081] *** VALIDATE selinux *** [ 0.025006] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.030254] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.031152] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032118] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.033113] *** VALIDATE tmpfs *** [ 0.034466] *** VALIDATE proc *** [ 0.036337] *** VALIDATE cgroup *** [ 0.037012] *** VALIDATE cgroup2 *** [ 0.038274] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.040044] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.041012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.042034] Spectre V2 : User space: Vulnerable [ 0.043008] Speculative Store Bypass: Vulnerable [ 0.046408] debug: unmapping init [mem 0xffffffffb7859000-0xffffffffb7860fff] [ 0.048177] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.049704] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.050027] ... version: 2 [ 0.051012] ... bit width: 48 [ 0.052013] ... generic registers: 4 [ 0.053013] ... value mask: 0000ffffffffffff [ 0.054012] ... max period: 00007fffffffffff [ 0.055015] ... fixed-purpose events: 3 [ 0.056015] ... event mask: 000000070000000f [ 0.058199] rcu: Hierarchical SRCU implementation. [ 0.060417] smp: Bringing up secondary CPUs ... [ 0.061576] x86: Booting SMP configuration: [ 0.062026] .... node #0, CPUs: #1 #2 #3 [ 0.066010] smp: Brought up 1 node, 4 CPUs [ 0.068018] smpboot: Max logical packages: 1 [ 0.069013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.120386] node 0 deferred pages initialised in 50ms [ 0.124130] devtmpfs: initialized [ 0.125297] x86/mm: Memory block size: 128MB [ 0.128082] gcov: version magic: 0x41383552 [ 0.130281] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.131081] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.132385] pinctrl core: initialized pinctrl subsystem [ 0.133194] [ 0.133815] ************************************************************* [ 0.134018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.135023] ** ** [ 0.136013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.137013] ** ** [ 0.138015] ** This means that this kernel is built to expose internal ** [ 0.139013] ** IOMMU data structures, which may compromise security on ** [ 0.140013] ** your system. ** [ 0.141014] ** ** [ 0.142012] ** If you see this message and you are not debugging the ** [ 0.143024] ** kernel, report this immediately to your vendor! ** [ 0.144012] ** ** [ 0.145014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.146013] ************************************************************* [ 0.147685] NET: Registered protocol family 16 [ 0.148536] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.149137] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.150148] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.152011] cpuidle: using governor menu [ 0.153932] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.157666] PCI: Using configuration type 1 for base access [ 0.159126] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.172074] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.175019] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.180067] cryptd: max_cpu_qlen set to 1000 [ 0.185264] ACPI: Added _OSI(Module Device) [ 0.187014] ACPI: Added _OSI(Processor Device) [ 0.189016] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.190014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.196602] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.203338] ACPI: Interpreter enabled [ 0.205059] ACPI: PM: (supports S0 S3 S4 S5) [ 0.207026] ACPI: Using IOAPIC for interrupt routing [ 0.208094] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.210322] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.220171] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.222041] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.226024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.229068] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.234401] acpiphp: Slot [2] registered [ 0.235218] acpiphp: Slot [5] registered [ 0.237457] acpiphp: Slot [6] registered [ 0.239159] acpiphp: Slot [7] registered [ 0.241118] acpiphp: Slot [8] registered [ 0.243192] acpiphp: Slot [9] registered [ 0.245178] acpiphp: Slot [10] registered [ 0.246195] acpiphp: Slot [3] registered [ 0.248114] acpiphp: Slot [4] registered [ 0.250108] acpiphp: Slot [11] registered [ 0.252106] acpiphp: Slot [12] registered [ 0.253117] acpiphp: Slot [13] registered [ 0.255074] acpiphp: Slot [14] registered [ 0.256000] acpiphp: Slot [15] registered [ 0.256000] acpiphp: Slot [16] registered [ 0.259085] acpiphp: Slot [17] registered [ 0.260108] acpiphp: Slot [18] registered [ 0.262082] acpiphp: Slot [19] registered [ 0.263062] acpiphp: Slot [20] registered [ 0.264061] acpiphp: Slot [21] registered [ 0.266184] acpiphp: Slot [22] registered [ 0.267106] acpiphp: Slot [23] registered [ 0.269112] acpiphp: Slot [24] registered [ 0.271102] acpiphp: Slot [25] registered [ 0.272092] acpiphp: Slot [26] registered [ 0.274093] acpiphp: Slot [27] registered [ 0.275105] acpiphp: Slot [28] registered [ 0.277093] acpiphp: Slot [29] registered [ 0.278091] acpiphp: Slot [30] registered [ 0.279063] acpiphp: Slot [31] registered [ 0.280084] PCI host bridge to bus 0000:00 [ 0.280917] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.283013] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.286022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.289034] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.292030] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.295022] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.296151] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.300043] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.303637] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.312611] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.319038] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.321018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.324024] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.327020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.331560] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.334903] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.337047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.340801] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.347015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.359073] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.364011] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.369057] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.378012] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.385019] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.401019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.411720] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.421017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.432042] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.456015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.472105] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.479013] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.490013] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.506012] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.517169] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.524014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.531012] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.548044] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.556728] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.564014] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.572019] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.587014] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.597661] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.605031] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.613018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.633015] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.646000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.647119] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.649294] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.651501] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.654224] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.659226] iommu: Default domain type: Passthrough [ 0.661515] SCSI subsystem initialized [ 0.663126] ACPI: bus type USB registered [ 0.664106] usbcore: registered new interface driver usbfs [ 0.667087] usbcore: registered new interface driver hub [ 0.669081] usbcore: registered new device driver usb [ 0.671162] pps_core: LinuxPPS API ver. 1 registered [ 0.672009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.676057] PTP clock support registered [ 0.678096] EDAC MC: Ver: 3.0.0 [ 0.680110] PCI: Using ACPI for IRQ routing [ 0.682781] NetLabel: Initializing [ 0.684012] NetLabel: domain hash size = 128 [ 0.685009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.687078] NetLabel: unlabeled traffic allowed by default [ 0.689282] vgaarb: loaded [ 0.691253] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.693015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.700000] clocksource: Switched to clocksource kvm-clock [ 0.803672] VFS: Disk quotas dquot_6.6.0 [ 0.804846] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.807794] *** VALIDATE ramfs *** [ 0.809214] *** VALIDATE hugetlbfs *** [ 0.811136] pnp: PnP ACPI init [ 0.814201] pnp: PnP ACPI: found 6 devices [ 0.829664] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.832932] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.835522] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.837035] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.838546] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.840160] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.843080] NET: Registered protocol family 2 [ 0.846099] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.851210] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.854229] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.858615] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.861647] TCP: Hash tables configured (established 65536 bind 65536) [ 0.864602] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.867091] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.869255] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.871284] NET: Registered protocol family 1 [ 0.874247] RPC: Registered named UNIX socket transport module. [ 0.876525] RPC: Registered udp transport module. [ 0.878298] RPC: Registered tcp transport module. [ 0.879986] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.882346] NET: Registered protocol family 44 [ 0.884044] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.886062] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.888090] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.890840] PCI: CLS 0 bytes, default 64 [ 0.893201] Unpacking initramfs... [ 2.299287] debug: unmapping init [mem 0xffff909abcc54000-0xffff909abffbffff] [ 2.304520] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.307188] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.310097] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.808120] Initialise system trusted keyrings [ 2.809996] Key type blacklist registered [ 2.811583] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.820265] zbud: loaded [ 2.823436] *** VALIDATE nfs *** [ 2.824834] *** VALIDATE nfs4 *** [ 2.826537] pstore: using deflate compression [ 2.830626] Platform Keyring initialized [ 2.933395] NET: Registered protocol family 38 [ 2.935200] Key type asymmetric registered [ 2.936714] Asymmetric key parser 'x509' registered [ 2.938934] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.942495] io scheduler mq-deadline registered [ 2.944421] io scheduler kyber registered [ 2.945979] io scheduler bfq registered [ 2.948125] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.951528] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.954440] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.957462] ACPI: Power Button [PWRF] [ 2.962793] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.970532] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.992672] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.003078] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.024460] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.053538] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.086100] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.091226] Non-volatile memory driver v1.3 [ 3.092295] Linux agpgart interface v0.103 [ 3.124882] virtio_blk virtio1: [vda] 145800 512-byte logical blocks (74.6 MB/71.2 MiB) [ 3.127669] vda: detected capacity change from 0 to 74649600 [ 3.143839] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.146667] vdb: detected capacity change from 0 to 1073741824 [ 3.161789] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.165422] vdc: detected capacity change from 0 to 2621440000 [ 3.183207] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.187117] vdd: detected capacity change from 0 to 2621440000 [ 3.207691] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.210986] vde: detected capacity change from 0 to 4294967296 [ 3.225731] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.229323] vdf: detected capacity change from 0 to 4294967296 [ 3.237699] libphy: Fixed MDIO Bus: probed [ 3.245545] usbcore: registered new interface driver usbserial_generic [ 3.247825] usbserial: USB Serial support registered for generic [ 3.250208] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.254453] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.256569] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.259281] mousedev: PS/2 mouse device common for all mice [ 3.262730] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.267057] rtc_cmos 00:05: RTC can wake from S4 [ 3.270245] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.272652] rtc_cmos 00:05: registered as rtc0 [ 3.277191] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.277231] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.283649] intel_pstate: CPU model not supported [ 3.286742] hid: raw HID events driver (C) Jiri Kosina [ 3.288926] usbcore: registered new interface driver usbhid [ 3.291119] usbhid: USB HID core driver [ 3.292811] drop_monitor: Initializing network drop monitor service [ 3.295197] Initializing XFRM netlink socket [ 3.297173] NET: Registered protocol family 10 [ 3.300315] Segment Routing with IPv6 [ 3.301881] NET: Registered protocol family 17 [ 3.304353] mpls_gso: MPLS GSO support [ 3.309423] RAS: Correctable Errors collector initialized. [ 3.311988] AVX version of gcm_enc/dec engaged. [ 3.313901] AES CTR mode by8 optimization enabled [ 3.398768] sched_clock: Marking stable (3398746842, 0)->(4352360523, -953613681) [ 3.402876] registered taskstats version 1 [ 3.405449] Loading compiled-in X.509 certificates [ 3.407330] zswap: loaded using pool lzo/zbud [ 3.433800] Key type big_key registered [ 3.446451] Key type encrypted registered [ 3.447712] ima: No TPM chip found, activating TPM-bypass! [ 3.450279] ima: Allocated hash algorithm: sha1 [ 3.452211] ima: No architecture policies found [ 3.454159] evm: Initialising EVM extended attributes: [ 3.456243] evm: security.selinux [ 3.457423] evm: security.ima [ 3.458232] evm: security.capability [ 3.459258] evm: HMAC attrs: 0x1 [ 3.461862] rtc_cmos 00:05: setting system clock to 2026-07-26 14:55:18 UTC (1785077718) [ 3.468502] debug: unmapping init [mem 0xffffffffb8803000-0xffffffffb89fffff] [ 3.471608] debug: unmapping init [mem 0xffffffffb7582000-0xffffffffb7858fff] [ 3.481280] Write protecting the kernel read-only data: 28672k [ 3.484617] debug: unmapping init [mem 0xffffffffb5c03000-0xffffffffb5dfffff] [ 3.487611] debug: unmapping init [mem 0xffffffffb6514000-0xffffffffb65fffff] [ 3.523341] 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.532403] systemd[1]: Detected virtualization kvm. [ 3.534794] systemd[1]: Detected architecture x86-64. [ 3.537267] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.563684] systemd[1]: No hostname configured. [ 3.565802] systemd[1]: Set hostname to . [ 3.568312] random: systemd: uninitialized urandom read (16 bytes read) [ 3.571607] systemd[1]: Initializing machine ID from random generator. [ 3.737531] random: systemd: uninitialized urandom read (16 bytes read) [ 3.741131] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.747667] random: systemd: uninitialized urandom read (16 bytes read) [ 3.750576] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.755040] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... [ OK ] Listening on udev Control Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Journal Service. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.481433] device-mapper: uevent: version 1.0.3 [ 4.484246] 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. Starting dracut initqueue hook... [ 5.293345] random: fast init done [ 5.309201] virtio_net virtio0 ens2: renamed from eth0 [ 5.471591] scsi host0: ata_piix [ 5.495814] scsi host1: ata_piix [ 5.497642] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.500292] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.240505] dracut-initqueue[585]: RTNETLINK answers: File exists [ 9.974995] random: crng init done [ 9.980209] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 11.597333] 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 Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems (Pre). Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ 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... [ 13.976652] printk: systemd: 21 output lines suppressed due to ratelimiting [ 14.724032] SELinux: Disabled at runtime. [ 14.828221] 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) [ 14.846199] systemd[1]: Detected virtualization kvm. [ 14.848801] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 16.572483] systemd[1]: initrd-switch-root.service: Succeeded. [ 16.579530] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 16.596796] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 16.606650] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 16.619366] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 16.635498] systemd[1]: Starting Journal Service... Starting Journal Service... [ 16.648441] systemd[1]: Starting Create list of required static device nodes for the current kernel... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Listening on udev Control Socket. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Switch Root. Starting Remount Root and Kernel File Systems... Starting udev Coldplug all Devices... Activating swap /dev/disk/by-label/SWAP... Mounting Huge Pages File System... [ OK ] Reached target rpc_pipefs.target. Mounting Kernel Debug File System... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on RPCbind Server Activation Socket. [ 16.991062] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Initrd Root File System. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Apply Kernel Variables... Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ 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 /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 18.082884] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 19.175431] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 19.182410] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 19.546019] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 19.642416] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (7s / no limit) [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 24.875370] Key type dns_resolver registered [ *** ] A start job is running for Configur…-only root support (9s / no limit)[ 25.556470] NFS: Registering the id_resolver key type [ 25.564787] Key type id_resolver registered [ 25.569355] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ 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 ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ 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 System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg341-server login: [ 41.862012] hrtimer: interrupt took 4372806 ns [ 81.940357] libcfs: loading out-of-tree module taints kernel. [ 81.999577] Key type ._llcrypt registered [ 82.002168] Key type .llcrypt registered [ 82.114864] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_hostid [ 100.028658] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 101.468759] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 101.494558] alg: No test for adler32 (adler32-zlib) [ 102.992942] Lustre: Lustre: Build Version: 2.17.54_162_gf7f7620 [ 103.813534] LNet: Added LNI 192.168.203.141@tcp [8/256/0/180] [ 105.600523] Key type lgssc registered [ 107.433468] Lustre: Echo OBD driver; http://www.lustre.org/ [ 119.790155] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 159.888772] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 174.006324] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 174.025401] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 175.260940] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 175.297597] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 175.367645] Lustre: lustre-MDT0000: new disk, initializing [ 175.450755] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 175.468122] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 180.554483] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 194.747788] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 194.858189] Lustre: 6519: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 [ 194.907407] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 194.914758] Lustre: Skipped 1 previous similar message [ 195.013339] Lustre: lustre-MDT0001: new disk, initializing [ 195.114956] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 195.146453] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 195.153338] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 199.432027] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 204.013137] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 212.138660] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 212.425993] Lustre: lustre-OST0000: new disk, initializing [ 212.432832] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 212.453701] Lustre: 8454:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 212.527451] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 213.181661] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 213.194168] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 213.328778] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 218.551706] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 231.796218] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 231.906413] Lustre: lustre-OST0001: new disk, initializing [ 231.911375] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 231.917672] Lustre: 9527:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 231.979595] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 237.384977] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 239.121587] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 239.142227] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 239.170650] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 248.781769] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 258.141972] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 265.266521] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing check_logdir /tmp/testlogs/ [ 271.320686] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing yml_node [ 275.243097] Lustre: DEBUG MARKER: Client: 2.17.54.162 [ 277.253019] Lustre: DEBUG MARKER: MDS: 2.17.54.162 [ 279.895653] Lustre: DEBUG MARKER: OSS: 2.17.54.162 [ 281.996568] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Sun Jul 26 10:59:55 EDT 2026 [ 297.421192] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 306.483455] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 312.803281] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 312.807278] 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 [ 312.816088] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 315.873206] 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 [ 315.880898] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 315.887022] Lustre: Skipped 2 previous similar messages [ 315.896102] Lustre: Skipped 2 previous similar messages [ 317.956942] Lustre: server umount lustre-MDT0000 complete [ 324.301680] LustreError: 6510:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785078039 with bad export cookie 13682659778389255260 [ 324.309329] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 324.311907] LustreError: 6510:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 324.668873] Lustre: server umount lustre-MDT0001 complete [ 341.971460] Lustre: server umount lustre-OST0000 complete [ 342.496233] Lustre: 3653:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078041/real 1785078041] req@ffff909b3ebfd500 x1871789758184448/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785078057 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 342.521953] 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 [ 345.061086] Lustre: 3655:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078044/real 1785078044] req@ffff909b041cd500 x1871789758184704/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785078060 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 347.682833] Lustre: 3653:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078046/real 1785078046] req@ffff909b3ebfc380 x1871789758184960/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785078062 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 348.845332] Lustre: server umount lustre-OST0001 complete [ 365.319727] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing unload_modules_local [ 367.823506] Key type lgssc unregistered [ 368.039965] LNet: 14810:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 368.048257] LNetError: 14810:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 369.066170] LNet: Removed LNI 192.168.203.141@tcp [ 369.832252] Key type .llcrypt unregistered [ 369.835544] Key type ._llcrypt unregistered [ 391.160624] Key type ._llcrypt registered [ 391.163690] Key type .llcrypt registered [ 391.290892] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_hostid [ 406.159188] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 407.227691] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 407.314423] alg: No test for adler32 (adler32-zlib) [ 408.556554] Lustre: Lustre: Build Version: 2.17.54_162_gf7f7620 [ 408.886111] LNet: Added LNI 192.168.203.141@tcp [8/256/0/180] [ 410.608164] Key type lgssc registered [ 411.752748] Lustre: Echo OBD driver; http://www.lustre.org/ [ 462.160281] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 478.032758] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 478.047594] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 479.228546] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 479.276690] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 479.399433] Lustre: lustre-MDT0000: new disk, initializing [ 479.514554] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 479.538489] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 483.445586] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 494.947440] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 495.067123] Lustre: 19266: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 [ 495.100766] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 495.110320] Lustre: Skipped 1 previous similar message [ 495.198237] Lustre: lustre-MDT0001: new disk, initializing [ 495.269121] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 495.290970] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 495.296830] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 499.155616] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 503.443132] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 512.624250] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 512.871027] Lustre: lustre-OST0000: new disk, initializing [ 512.879342] Lustre: lustre-OST0000: Not available for connect from 0@lo (not set up) [ 512.890361] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 512.902945] Lustre: 21203:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 512.969665] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 518.137433] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 518.147520] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 518.222033] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 519.440630] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 532.613897] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 532.751995] Lustre: lustre-OST0001: new disk, initializing [ 532.755797] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 532.764856] Lustre: 22229:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 532.817916] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 539.166605] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 539.668373] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 539.688653] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 539.757589] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 549.579253] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 558.549778] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 565.908473] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 11:04:39 (1785078279) === [ 568.602298] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 11:04:42 (1785078282) [ 568.730882] Lustre: 19272:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 568.744827] Lustre: 19272:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 568.757189] Lustre: 19272:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 568.768091] Lustre: 19272:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 568.779369] Lustre: 19272:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 568.791035] Lustre: 19272:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 569.242249] Lustre: 19273:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 569.252517] Lustre: 19273:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 8 previous similar messages [ 569.268897] Lustre: 19273:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 569.280257] Lustre: 19273:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 569.293656] Lustre: 19273:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 569.307629] Lustre: 19273:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 569.316929] Lustre: 19273:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 569.326794] Lustre: 19273:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 569.334754] Lustre: 19273:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 569.340440] Lustre: 19273:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 569.346602] Lustre: 19273:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 569.355617] Lustre: 19273:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 570.250396] Lustre: 19271:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 570.259754] Lustre: 19271:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 32 previous similar messages [ 570.301617] Lustre: 19271:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 570.306684] Lustre: 19271:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 570.321709] Lustre: 19271:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 570.327140] Lustre: 19271:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 570.331584] Lustre: 19271:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 570.340613] Lustre: 19271:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 570.348124] Lustre: 19271:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 570.353963] Lustre: 19271:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 570.359898] Lustre: 19271:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 570.364561] Lustre: 19271:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 572.325140] Lustre: 21982:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 572.332054] Lustre: 21982:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 104 previous similar messages [ 572.342394] Lustre: 21982:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 572.353572] Lustre: 21982:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 572.360068] Lustre: 21982:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 572.372761] Lustre: 21982:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 572.383152] Lustre: 21982:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 572.388445] Lustre: 21982:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 572.393836] Lustre: 21982:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 572.401110] Lustre: 21982:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 572.406818] Lustre: 21982:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 572.413111] Lustre: 21982:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 576.033660] Lustre: *** cfs_fail_loc=1600, val=3*** [ 578.949918] Lustre: 23417:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 578.953166] Lustre: 21192:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 578.958582] Lustre: 23417:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 131 previous similar messages [ 578.968159] Lustre: 21192:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 130 previous similar messages [ 578.968181] Lustre: 21192:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 578.968185] Lustre: 21192:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 130 previous similar messages [ 578.968191] Lustre: 21192:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 578.968194] Lustre: 21192:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 130 previous similar messages [ 578.968198] Lustre: 21192:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 578.968201] Lustre: 21192:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 130 previous similar messages [ 578.968207] Lustre: 21192:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 578.968210] Lustre: 21192:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 130 previous similar messages [ 580.407142] Lustre: *** cfs_fail_loc=1600, val=3*** [ 590.783875] Lustre: 23671:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 590.797847] Lustre: 23671:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 56 previous similar messages [ 590.807355] Lustre: 23671:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 590.809448] Lustre: 21191:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 590.812859] Lustre: 23671:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 590.812882] Lustre: 23671:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 590.812887] Lustre: 23671:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 61 previous similar messages [ 590.812893] Lustre: 23671:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 590.812896] Lustre: 23671:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 61 previous similar messages [ 590.812900] Lustre: 23671:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 590.812903] Lustre: 23671:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 61 previous similar messages [ 590.891322] Lustre: 21191:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 592.865844] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 592.878803] 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 [ 592.892873] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 595.936734] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 595.939266] 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 [ 595.967408] Lustre: Skipped 1 previous similar message [ 601.062458] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 601.071447] Lustre: Skipped 6 previous similar messages [ 606.179738] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 606.186735] Lustre: Skipped 3 previous similar messages [ 607.200135] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 607.420177] Lustre: server umount lustre-MDT0000 complete [ 610.432780] LustreError: 22997:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785078325 with bad export cookie 7999417174836112814 [ 610.434490] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 610.442860] LustreError: 22997:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 610.721218] Lustre: server umount lustre-MDT0001 complete [ 624.700169] Lustre: server umount lustre-OST0000 complete [ 627.682982] Lustre: 16426:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078326/real 1785078326] req@ffff909b035e8700 x1871790078012544/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785078342 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 627.722221] 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 [ 627.741725] Lustre: Skipped 1 previous similar message [ 628.744077] Lustre: server umount lustre-OST0001 complete [ 636.567985] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 11:05:50 (1785078350) [ 650.279578] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 660.125192] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 660.612985] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 665.070819] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 666.083088] LustreError: 26288:0:(ldlm_lib.c:1192: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. [ 666.097888] LustreError: 26288:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 670.185649] LustreError: 26287:0:(ldlm_lib.c:1192: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. [ 673.683035] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 673.917477] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 678.628419] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 681.704415] Lustre: 27428:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 690.075314] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 690.819378] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 698.979516] LustreError: 27786:0:(ldlm_lib.c:1192: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. [ 699.615530] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 704.496164] LustreError: 27784:0:(ldlm_lib.c:1192: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. [ 705.550178] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:40 to 0x280000401:65) [ 708.522194] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 714.216150] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 715.024099] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 721.469670] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 724.705567] Lustre: 29300:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 726.058285] Lustre: 26282:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 726.065028] Lustre: 26282:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 6 previous similar messages [ 726.072106] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 726.075733] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 726.081555] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 726.086475] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 726.091389] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 726.096525] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 726.103067] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 726.113737] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 726.121397] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 726.128986] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 730.208563] Lustre: *** cfs_fail_loc=1501, val=0*** [ 736.886781] Lustre: Failing over lustre-MDT0000 [ 737.092309] Lustre: server umount lustre-MDT0000 complete [ 739.812051] 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 [ 739.824828] LustreError: 28420:0:(ldlm_lib.c:1192: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. [ 739.825612] Lustre: Skipped 2 previous similar messages [ 739.847020] LustreError: 28420:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 745.564848] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 745.695780] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 745.890245] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 745.897580] Lustre: Skipped 1 previous similar message [ 745.936394] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 749.356254] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 751.079056] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 751.085449] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 751.114838] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 751.162272] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 751.164676] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 752.236529] Lustre: *** cfs_fail_loc=1505, val=0*** [ 758.699833] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 11:07:52 (1785078472) [ 759.613538] Lustre: 27582:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 759.625593] Lustre: 27582:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 322 previous similar messages [ 759.632100] Lustre: 27582:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 759.638703] Lustre: 27582:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 759.648165] Lustre: 27582:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 759.654397] Lustre: 27582:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 759.661953] Lustre: 27582:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 759.668616] Lustre: 27582:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 759.674482] Lustre: 27582:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 759.680527] Lustre: 27582:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 759.685794] Lustre: 27582:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 759.689851] Lustre: 27582:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 764.029393] Lustre: *** cfs_fail_loc=1502, val=0*** [ 773.156773] Lustre: Failing over lustre-MDT0000 [ 773.489335] Lustre: server umount lustre-MDT0000 complete [ 776.673495] 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 [ 776.675812] LustreError: 26287:0:(ldlm_lib.c:1192: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. [ 776.675966] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 776.689216] Lustre: Skipped 3 previous similar messages [ 776.733800] LustreError: 26287:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 7 previous similar messages [ 781.949314] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 782.039813] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 782.303333] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 785.585993] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 787.433128] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 787.434524] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 787.452245] Lustre: Skipped 3 previous similar messages [ 787.477309] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 787.514082] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 787.514144] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 788.672531] Lustre: *** cfs_fail_loc=1505, val=0*** [ 795.851820] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 11:08:29 (1785078509) [ 802.343203] Lustre: *** cfs_fail_loc=1504, val=0*** [ 802.344941] Lustre: *** cfs_fail_loc=1504, val=0*** [ 802.350565] Lustre: Skipped 1 previous similar message [ 810.528109] Lustre: Failing over lustre-MDT0000 [ 811.126236] Lustre: server umount lustre-MDT0000 complete [ 813.026480] 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 [ 813.032322] LustreError: 28420:0:(ldlm_lib.c:1192: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. [ 813.056187] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 813.068169] Lustre: Skipped 4 previous similar messages [ 813.130357] LustreError: 28420:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 7 previous similar messages [ 825.737170] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 825.886553] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 826.274681] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 826.290805] Lustre: Skipped 1 previous similar message [ 826.350797] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 831.037697] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 831.469682] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 831.474907] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 831.481758] Lustre: Skipped 3 previous similar messages [ 831.499259] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 831.555288] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 831.562189] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 834.514493] Lustre: *** cfs_fail_loc=1505, val=0*** [ 841.410676] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 11:09:15 (1785078555) [ 842.326454] Lustre: 27582:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 842.335838] Lustre: 27582:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 644 previous similar messages [ 842.341910] Lustre: 27582:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 842.348234] Lustre: 27582:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 842.353656] Lustre: 27582:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 842.359163] Lustre: 27582:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 842.363798] Lustre: 27582:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 842.372359] Lustre: 27582:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 842.379092] Lustre: 27582:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 842.384817] Lustre: 27582:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 842.391244] Lustre: 27582:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 842.395162] Lustre: 27582:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 847.182348] Lustre: *** cfs_fail_loc=1603, val=0*** [ 854.337375] Lustre: Failing over lustre-MDT0000 [ 856.527638] Lustre: server umount lustre-MDT0000 complete [ 857.057747] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 857.070021] 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 [ 857.074744] LustreError: 26284:0:(ldlm_lib.c:1192: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. [ 857.074753] LustreError: 26284:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 857.137751] Lustre: Skipped 3 previous similar messages [ 865.782885] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 865.894973] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 866.140658] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 870.109535] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 871.396088] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 871.398540] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 871.410903] Lustre: Skipped 3 previous similar messages [ 871.423163] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 871.451987] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 871.452182] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 878.416201] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 11:09:52 (1785078592) [ 883.927960] Lustre: *** cfs_fail_loc=1604, val=0*** [ 892.517552] Lustre: Failing over lustre-MDT0000 [ 893.008337] Lustre: server umount lustre-MDT0000 complete [ 896.993261] 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 [ 896.996602] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 897.025043] Lustre: Skipped 2 previous similar messages [ 904.924347] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 905.096509] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 905.325265] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 909.248392] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 910.306975] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 910.310208] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 910.333757] Lustre: Skipped 3 previous similar messages [ 910.366864] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 910.433488] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 910.434890] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 917.408548] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 11:10:31 (1785078631) [ 923.212199] Lustre: *** cfs_fail_loc=1605, val=0*** [ 930.839561] Lustre: Failing over lustre-MDT0000 [ 931.216361] Lustre: server umount lustre-MDT0000 complete [ 935.913554] LustreError: 26284:0:(ldlm_lib.c:1192: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. [ 935.940089] LustreError: 26284:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 18 previous similar messages [ 942.192848] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 942.323208] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 942.636095] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 946.602234] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 947.688372] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 947.699529] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 947.717030] Lustre: Skipped 3 previous similar messages [ 947.743491] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 947.789774] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 947.789777] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 957.007365] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 11:11:10 (1785078670) [ 966.676703] Lustre: *** cfs_fail_loc=161d, val=0*** [ 971.051074] Lustre: 29427:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 971.061787] Lustre: 29423:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 971.073041] Lustre: 29427:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1263 previous similar messages [ 971.073070] Lustre: 29427:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 971.073074] Lustre: 29427:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1262 previous similar messages [ 971.073080] Lustre: 29427:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 971.073084] Lustre: 29427:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1262 previous similar messages [ 971.073088] Lustre: 29427:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 971.073091] Lustre: 29427:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1262 previous similar messages [ 971.073096] Lustre: 29427:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 971.073099] Lustre: 29427:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1262 previous similar messages [ 971.290777] Lustre: 29423:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1269 previous similar messages [ 977.825964] Lustre: Failing over lustre-MDT0000 [ 978.138279] Lustre: server umount lustre-MDT0000 complete [ 978.402148] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 978.405063] 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 [ 978.449299] Lustre: Skipped 7 previous similar messages [ 989.045953] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 989.275670] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 989.678129] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 989.681294] Lustre: Skipped 3 previous similar messages [ 989.731584] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 994.777697] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 994.786990] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 994.797714] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 994.797723] Lustre: Skipped 3 previous similar messages [ 994.854805] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 994.913358] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 994.917937] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 1003.584587] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 11:11:57 (1785078717) [ 1005.884878] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1015.993881] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 11:12:10 (1785078730) [ 1021.245723] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1022.300927] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1032.729271] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 11:12:26 (1785078746) [ 1067.432450] Lustre: Failing over lustre-MDT0000 [ 1067.806307] Lustre: server umount lustre-MDT0000 complete [ 1071.587740] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1071.589698] LustreError: 26284:0:(ldlm_lib.c:1192: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. [ 1071.646376] LustreError: 26284:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 17 previous similar messages [ 1073.778076] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1087.971305] Lustre: 16426:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078786/real 1785078786] req@ffff909b2730ea00 x1871790078653184/t0(0) o400->MGC192.168.203.141@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1785078802 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1088.037321] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1088.211994] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1102.545718] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1102.575246] Lustre: lustre-MDT0000: reset Object Index mappings [ 1113.570146] LustreError: 16422:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff909b0861dc00 x1871790078666496/t0(0) o250->MGC192.168.203.141@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 [ 1113.991768] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1118.103671] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1119.215429] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1119.227975] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1119.234941] Lustre: Skipped 3 previous similar messages [ 1119.248086] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1119.308951] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1119.314824] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1121.532271] LustreError: 42937:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1121.558519] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1123.622279] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1123.626577] Lustre: Skipped 1 previous similar message [ 1130.195812] Lustre: Failing over lustre-MDT0000 [ 1130.432548] Lustre: server umount lustre-MDT0000 complete [ 1134.561030] 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 [ 1134.562875] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1134.588210] Lustre: Skipped 8 previous similar messages [ 1141.264710] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1145.774988] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1146.924652] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1146.926725] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1149.202252] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1156.459614] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 11:14:30 (1785078870) [ 1158.840568] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1167.184741] Lustre: Failing over lustre-MDT0000 [ 1167.331258] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1167.338452] Lustre: Skipped 3 previous similar messages [ 1167.729528] Lustre: server umount lustre-MDT0000 complete [ 1173.372738] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1183.840293] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1188.834277] Lustre: 16424:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785078887/real 1785078887] req@ffff909b42077480 x1871790078749824/t0(0) o400->MGC192.168.203.141@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1785078903 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1194.844264] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1194.867479] Lustre: lustre-MDT0000: reset Object Index mappings [ 1198.322937] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1198.326986] Lustre: Skipped 1 previous similar message [ 1203.025321] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1203.682065] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1203.686650] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1203.690958] Lustre: Skipped 1 previous similar message [ 1203.694167] Lustre: Skipped 7 previous similar messages [ 1203.726875] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1203.738281] Lustre: Skipped 1 previous similar message [ 1203.759414] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1203.760970] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1206.835727] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1206.837770] Lustre: Skipped 2 previous similar messages [ 1215.072201] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1215.075110] Lustre: Skipped 7 previous similar messages [ 1220.855136] Lustre: Failing over lustre-MDT0000 [ 1221.291171] Lustre: server umount lustre-MDT0000 complete [ 1224.161461] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1224.172340] LustreError: Skipped 1 previous similar message [ 1231.857242] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1231.981526] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1231.993749] LustreError: Skipped 2 previous similar messages [ 1236.199569] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1237.529185] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1237.530133] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1239.014117] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1239.016596] Lustre: Skipped 84 previous similar messages [ 1246.596343] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 11:16:00 (1785078960) [ 1247.986638] Lustre: 26284:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 1247.991667] Lustre: 26284:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 998 previous similar messages [ 1247.995823] Lustre: 26284:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 1247.999445] Lustre: 26284:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 991 previous similar messages [ 1248.002907] Lustre: 26284:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1248.009812] Lustre: 26284:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 999 previous similar messages [ 1248.014085] Lustre: 26284:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1248.017538] Lustre: 26284:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 999 previous similar messages [ 1248.021250] Lustre: 26284:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1248.024558] Lustre: 26284:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 999 previous similar messages [ 1248.028184] Lustre: 26284:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1248.032312] Lustre: 26284:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 999 previous similar messages [ 1253.986314] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1275.388939] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 11:16:29 (1785078989) [ 1286.240477] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1286.248554] Lustre: Skipped 11 previous similar messages [ 1306.785503] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 11:17:00 (1785079020) [ 1325.043339] Lustre: Failing over lustre-MDT0000 [ 1325.441563] Lustre: server umount lustre-MDT0000 complete [ 1329.666944] LustreError: 26282:0:(ldlm_lib.c:1192: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. [ 1329.723397] LustreError: 26282:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 83 previous similar messages [ 1336.101810] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1336.579813] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1336.583596] Lustre: Skipped 4 previous similar messages [ 1336.632812] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1336.648823] Lustre: Skipped 1 previous similar message [ 1341.147948] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1341.924125] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1341.932498] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1341.933171] Lustre: Skipped 1 previous similar message [ 1341.944522] Lustre: Skipped 7 previous similar messages [ 1341.979370] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1341.992517] Lustre: Skipped 1 previous similar message [ 1342.055469] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:853 to 0x280000401:897) [ 1342.055724] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:854 to 0x2c0000401:897) [ 1349.960866] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 11:17:44 (1785079064) [ 1366.356164] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 1387.939805] Lustre: 53002:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1408.760368] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1412.134393] Lustre: 54137:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1419.019378] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1419.030950] Lustre: Skipped 81 previous similar messages [ 1421.473864] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1422.496265] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1423.520412] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1425.577632] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1425.587241] Lustre: Skipped 1 previous similar message [ 1426.456321] Lustre: Failing over lustre-MDT0000 [ 1427.257434] Lustre: server umount lustre-MDT0000 complete [ 1428.961783] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1428.965133] 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 [ 1428.990280] Lustre: Skipped 15 previous similar messages [ 1437.727067] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1443.392630] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1443.401937] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1443.675279] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1452.006135] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 11:19:25 (1785079165) [ 1458.677090] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1458.691555] Lustre: Skipped 2 previous similar messages [ 1460.526494] Lustre: server umount lustre-MDT0000 complete [ 1464.558200] LustreError: 26269:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785079179 with bad export cookie 7999417174836327840 [ 1464.576812] LustreError: 26269:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1464.823989] Lustre: server umount lustre-MDT0001 complete [ 1478.329878] Lustre: server umount lustre-OST0000 complete [ 1492.350632] Lustre: server umount lustre-OST0001 complete [ 1497.649730] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_hostid [ 1505.094842] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 1544.038810] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 1553.612465] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1553.801520] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1553.822990] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1553.887962] Lustre: lustre-MDT0000: new disk, initializing [ 1553.997838] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1558.074996] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1568.095865] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1568.206263] Lustre: 59195: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 [ 1568.263513] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1568.274266] Lustre: Skipped 1 previous similar message [ 1568.399845] Lustre: lustre-MDT0001: new disk, initializing [ 1568.485675] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1568.501477] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1572.812588] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1577.925216] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1584.192083] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1584.403408] Lustre: lustre-OST0000: new disk, initializing [ 1584.406904] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1584.411902] Lustre: 60826:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1585.764337] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1585.773992] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1585.907346] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1589.940254] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1599.337990] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1599.452427] Lustre: lustre-OST0001: new disk, initializing [ 1599.456502] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1599.465787] Lustre: 61695:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1601.426914] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1601.434333] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1601.487854] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1605.150595] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1613.697762] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1617.005483] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1626.314285] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1627.089336] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1627.096119] Lustre: Skipped 19 previous similar messages [ 1630.580480] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1630.587634] Lustre: Skipped 15 previous similar messages [ 1646.242463] Lustre: Failing over lustre-MDT0000 [ 1646.468523] Lustre: server umount lustre-MDT0000 complete [ 1653.999677] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1654.167205] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1654.177852] LustreError: Skipped 3 previous similar messages [ 1654.417954] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1654.426695] Lustre: Skipped 1 previous similar message [ 1658.177989] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1659.881741] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1659.882290] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1659.890015] Lustre: Skipped 7 previous similar messages [ 1659.920021] Lustre: Skipped 1 previous similar message [ 1659.936425] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1659.944904] Lustre: Skipped 1 previous similar message [ 1659.974711] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1659.981878] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1659.982452] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1665.261166] Lustre: Failing over lustre-MDT0000 [ 1665.496160] Lustre: server umount lustre-MDT0000 complete [ 1673.194166] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1677.485649] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1678.885634] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1678.891659] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1678.896145] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1682.016239] Lustre: Failing over lustre-MDT0000 [ 1682.215702] Lustre: server umount lustre-MDT0000 complete [ 1689.538247] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1693.681606] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1695.241630] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1695.243164] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1698.398795] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1708.811356] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 11:23:43 (1785079423) [ 1720.233221] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 1736.351333] Lustre: 68648:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1754.999757] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1758.102646] Lustre: 69783:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1766.114530] Lustre: 59202:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1766.121186] Lustre: 59202:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 2716 previous similar messages [ 1766.125796] Lustre: 59202:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1766.130217] Lustre: 59202:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2717 previous similar messages [ 1766.134927] Lustre: 59202:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1766.141945] Lustre: 59202:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2717 previous similar messages [ 1766.150072] Lustre: 59202:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1766.155577] Lustre: 59202:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2717 previous similar messages [ 1766.159806] Lustre: 59202:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1766.164085] Lustre: 59202:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2717 previous similar messages [ 1766.169143] Lustre: 59202:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1766.173765] Lustre: 59202:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2717 previous similar messages [ 1860.609371] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 11:26:14 (1785079574) [ 1905.516817] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1905.519069] Lustre: Skipped 4 previous similar messages [ 1928.138750] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1928.140673] Lustre: Skipped 7 previous similar messages [ 1964.521685] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 11:27:57 (1785079677) [ 2008.710858] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2016.711870] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2016.716847] Lustre: Skipped 447 previous similar messages [ 2032.719177] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2032.721197] Lustre: Skipped 876 previous similar messages [ 2064.726397] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2064.730243] Lustre: Skipped 1882 previous similar messages [ 2071.389632] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2071.394140] Lustre: Skipped 2599 previous similar messages [ 2283.306361] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 11:33:17 (1785079997) [ 2418.345602] Lustre: 71792:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 2418.354688] Lustre: 71792:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 36832 previous similar messages [ 2418.359703] Lustre: 71792:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2418.365234] Lustre: 71792:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2418.374579] Lustre: 71792:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2418.382924] Lustre: 71792:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2418.389630] Lustre: 71792:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2418.395019] Lustre: 71792:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2418.405586] Lustre: 71792:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2418.411875] Lustre: 71792:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2418.421114] Lustre: 71792:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2418.426588] Lustre: 71792:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 36832 previous similar messages [ 2425.312711] 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 [ 2425.330823] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2425.331015] Lustre: Skipped 19 previous similar messages [ 2425.350499] Lustre: Skipped 4 previous similar messages [ 2429.904784] Lustre: server umount lustre-MDT0000 complete [ 2430.437328] LustreError: 70202:0:(ldlm_lib.c:1192: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. [ 2430.459228] LustreError: 70202:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 39 previous similar messages [ 2433.107157] LustreError: 59187:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785080148 with bad export cookie 7999417174836346943 [ 2433.114271] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2433.122808] LustreError: 59187:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2433.142457] LustreError: Skipped 2 previous similar messages [ 2433.546797] Lustre: server umount lustre-MDT0001 complete [ 2447.449510] Lustre: server umount lustre-OST0000 complete [ 2460.195355] Lustre: server umount lustre-OST0001 complete [ 2465.594307] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2472.293658] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2487.840817] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2492.960378] LustreError: 75402:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.203.141@tcp: failed processing log, type 4: rc = -110 [ 2518.560226] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2518.563210] Lustre: Skipped 8 previous similar messages [ 2523.925481] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2526.720599] Lustre: 75986: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. [ 2526.742540] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2529.767677] Lustre: 75986:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2537.094563] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 11:37:31 (1785080251) [ 2549.519702] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 2558.272051] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2559.009546] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2564.016493] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2572.131860] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2577.331644] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2580.130536] Lustre: 78648:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2593.675753] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2593.833813] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2593.837732] Lustre: Skipped 2 previous similar messages [ 2598.903337] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2599.658677] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2606.465128] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2609.386752] Lustre: 80146:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2613.574592] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2619.788569] Lustre: Failing over lustre-OST0000 [ 2619.921388] Lustre: server umount lustre-OST0000 complete [ 2620.389192] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2620.397570] LustreError: Skipped 7 previous similar messages [ 2629.060949] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2629.307838] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2629.320097] Lustre: Skipped 2 previous similar messages [ 2630.566928] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2630.582931] Lustre: Skipped 2 previous similar messages [ 2630.618113] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2630.621814] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2630.623450] Lustre: *** cfs_fail_loc=215, val=0*** [ 2630.636686] Lustre: Skipped 2 previous similar messages [ 2630.671216] Lustre: Skipped 11 previous similar messages [ 2635.744712] Lustre: *** cfs_fail_loc=215, val=0*** [ 2635.752344] Lustre: Skipped 18 previous similar messages [ 2636.798604] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2639.849802] Lustre: *** cfs_fail_loc=215, val=0*** [ 2639.862214] Lustre: Skipped 1 previous similar message [ 2640.892310] Lustre: 81548: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. [ 2640.943674] Lustre: 81548:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2643.441304] Lustre: Failing over lustre-OST0000 [ 2643.523271] Lustre: server umount lustre-OST0000 complete [ 2650.651339] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2652.223979] Lustre: *** cfs_fail_loc=215, val=0*** [ 2652.235289] Lustre: Skipped 1 previous similar message [ 2655.245840] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2657.253124] Lustre: *** cfs_fail_loc=215, val=0*** [ 2657.258587] Lustre: Skipped 2 previous similar messages [ 2661.345758] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2661.351640] Lustre: Skipped 3 previous similar messages [ 2666.429982] Lustre: server umount lustre-MDT0000 complete [ 2669.321814] LustreError: 75408:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785080384 with bad export cookie 7999417174837905367 [ 2669.338711] LustreError: 75408:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2669.621328] Lustre: server umount lustre-MDT0001 complete [ 2683.620915] Lustre: server umount lustre-OST0000 complete [ 2696.176333] Lustre: server umount lustre-OST0001 complete [ 2702.478796] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 11:40:16 (1785080416) [ 2714.943432] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 2722.950525] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2723.518413] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2723.525630] Lustre: Skipped 2 previous similar messages [ 2727.543583] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2734.471051] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2738.520334] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2741.169917] Lustre: 85931:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2746.723279] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2748.983930] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 2752.462058] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2759.987068] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2765.265531] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2765.288186] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 2771.445431] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2774.272354] Lustre: 87799:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2802.578230] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 11:41:56 (1785080516) [ 2815.753319] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 11:42:09 (1785080529) [ 2817.342302] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2827.149434] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 11:42:21 (1785080541) [ 2830.287157] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2830.297295] Lustre: Skipped 7 previous similar messages [ 2877.922246] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2877.933061] Lustre: Skipped 3 previous similar messages [ 2882.321996] Lustre: server umount lustre-MDT0000 complete [ 2887.376666] LustreError: 84770:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785080602 with bad export cookie 7999417174837913830 [ 2887.396399] LustreError: 84770:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2888.020960] Lustre: server umount lustre-MDT0001 complete [ 2902.425256] Lustre: server umount lustre-OST0000 complete [ 2904.546954] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785080603/real 1785080603] req@ffff909a0d607b80 x1871790083126528/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785080619 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2906.067783] Lustre: server umount lustre-OST0001 complete [ 2919.669601] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 2929.377756] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2934.444454] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2943.120357] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2947.969187] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2950.262259] Lustre: 93674:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2955.486757] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2960.787685] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2968.952759] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 2969.549133] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2974.912544] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 2974.914322] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 2975.022100] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 2976.271679] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2982.875212] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2985.852190] Lustre: 95544:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2992.038243] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 11:45:05 (1785080705) [ 2996.332033] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2996.334156] Lustre: Skipped 63 previous similar messages [ 3016.164657] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3016.193525] Lustre: Skipped 3 previous similar messages [ 3021.918417] Lustre: server umount lustre-MDT0000 complete [ 3025.427701] LustreError: 95546:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785080740 with bad export cookie 7999417174837942236 [ 3025.445476] LustreError: 95546:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3025.830508] Lustre: server umount lustre-MDT0001 complete [ 3039.727467] Lustre: server umount lustre-OST0000 complete [ 3042.593068] Lustre: 16423:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785080741/real 1785080741] req@ffff909b27304000 x1871790083246080/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785080757 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3042.621288] 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 [ 3042.638728] Lustre: Skipped 17 previous similar messages [ 3043.198425] Lustre: server umount lustre-OST0001 complete [ 3056.340072] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 3065.924634] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3066.350383] LustreError: 98435:0:(ldlm_lib.c:1192: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. [ 3066.371042] LustreError: 98435:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 43 previous similar messages [ 3066.403582] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3066.407599] Lustre: Skipped 7 previous similar messages [ 3070.881130] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3077.867989] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3081.746318] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3084.071338] Lustre: 99576:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3089.807093] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3091.187161] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3095.119979] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3101.839848] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3103.023171] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3103.043961] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3103.080080] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3106.666680] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3112.762202] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3121.103688] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 11:47:15 (1785080835) [ 3123.009937] Lustre: 101310:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3123.030851] Lustre: 101310:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1695 previous similar messages [ 3123.039428] Lustre: 101310:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3123.050804] Lustre: 101310:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1695 previous similar messages [ 3123.058173] Lustre: 101310:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3123.082790] Lustre: 101310:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1695 previous similar messages [ 3123.101976] Lustre: 101310:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3123.119988] Lustre: 101310:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1695 previous similar messages [ 3123.134269] Lustre: 101310:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3123.145083] Lustre: 101310:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1695 previous similar messages [ 3123.159918] Lustre: 101310:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3123.171071] Lustre: 101310:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1695 previous similar messages [ 3124.875690] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3124.882199] Lustre: Skipped 63 previous similar messages [ 3125.229694] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3135.855907] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 11:47:29 (1785080849) [ 3138.889066] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3138.927142] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3138.931968] Lustre: Skipped 2 previous similar messages [ 3148.946940] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 11:47:42 (1785080862) [ 3150.662684] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3152.180678] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 11:47:46 (1785080866) [ 3157.982312] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3158.070581] LustreError: 98443:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3158.081367] LustreError: 98443:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s50 failed: rc = -5 [ 3175.845235] LustreError: 98432:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x4e:0x0]:1 for the striped directory [0x240002340:0x89:0x0] is out of the known LMV EA range [0 - 0], failout [ 3180.460076] LustreError: 101310:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x4e:0x0]:1 for the striped directory [0x240002340:0x89:0x0] is out of the known LMV EA range [0 - 0], failout [ 3180.482740] LustreError: 101310:0:(mdt_handler.c:1498:mdt_getattr_internal()) lustre-MDT0001: getattr error for [0x240002340:0x89:0x0]: rc = -5 [ 3220.968336] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3220.974335] Lustre: Skipped 5 previous similar messages [ 3224.071331] Lustre: server umount lustre-MDT0000 complete [ 3232.145987] LustreError: 98418:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785080947 with bad export cookie 7999417174837956964 [ 3232.155686] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3232.157610] LustreError: 98418:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3232.174626] LustreError: Skipped 3 previous similar messages [ 3232.453560] Lustre: server umount lustre-MDT0001 complete [ 3249.815365] Lustre: server umount lustre-OST0000 complete [ 3252.704735] Lustre: 16425:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785080951/real 1785080951] req@ffff909a0ae04380 x1871790083782272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785080967 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3256.824334] Lustre: server umount lustre-OST0001 complete [ 3271.783675] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing unload_modules_local [ 3274.509541] Key type lgssc unregistered [ 3274.802602] LNet: 105277:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3274.810992] LNetError: 105277:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3274.832594] LNet: Removed LNI 192.168.203.141@tcp [ 3275.791381] Key type .llcrypt unregistered [ 3275.796929] Key type ._llcrypt unregistered [ 3300.683340] Key type ._llcrypt registered [ 3300.693106] Key type .llcrypt registered [ 3300.919810] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_hostid [ 3314.471613] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 3315.432427] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3315.459827] alg: No test for adler32 (adler32-zlib) [ 3316.678168] Lustre: Lustre: Build Version: 2.17.54_162_gf7f7620 [ 3316.963800] LNet: Added LNI 192.168.203.141@tcp [8/256/0/180] [ 3318.728674] Key type lgssc registered [ 3320.106032] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3366.475901] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 3378.664076] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3378.701127] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3379.962477] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3380.010950] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3380.106463] Lustre: lustre-MDT0000: new disk, initializing [ 3380.167023] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3380.193544] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3384.663231] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3396.251204] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3396.366159] Lustre: 109725: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 [ 3396.428072] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3396.433608] Lustre: Skipped 1 previous similar message [ 3396.511615] Lustre: lustre-MDT0001: new disk, initializing [ 3396.572823] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3396.597977] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3396.608909] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3400.336449] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3405.123053] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3413.688147] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3413.936518] Lustre: lustre-OST0000: new disk, initializing [ 3413.950619] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3413.956522] Lustre: 111663:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3414.028075] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3420.139666] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3420.699817] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3420.718509] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3420.803388] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3434.014968] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3434.153167] Lustre: lustre-OST0001: new disk, initializing [ 3434.156843] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3434.162715] Lustre: 112687:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3434.225718] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3440.382488] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3442.228648] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3442.243345] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3442.293597] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3451.637869] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3458.470495] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3463.797389] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 11:52:57 (1785081177) === [ 3469.985549] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 11:53:03 (1785081183) [ 3470.290331] Lustre: 109731:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3470.318817] Lustre: 109731:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3470.331239] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3470.346142] Lustre: 109731:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3470.357382] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3470.368980] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3470.953045] Lustre: 109731:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3470.961738] Lustre: 109731:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 9 previous similar messages [ 3470.974432] Lustre: 109731:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3470.983786] Lustre: 109731:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3470.991700] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3471.001030] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3471.007110] Lustre: 109731:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 7/369/2 [ 3471.013381] Lustre: 109731:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3471.016849] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3471.023731] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3471.029321] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3471.033805] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3471.953586] Lustre: 109733:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 3471.959607] Lustre: 109733:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 242 previous similar messages [ 3471.979952] Lustre: 112041:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3471.986291] Lustre: 112041:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 248 previous similar messages [ 3471.991703] Lustre: 112041:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3471.998877] Lustre: 112041:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 248 previous similar messages [ 3472.012903] Lustre: 109732:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3472.017964] Lustre: 109732:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 251 previous similar messages [ 3472.022791] Lustre: 109732:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3472.026905] Lustre: 109732:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 251 previous similar messages [ 3472.031679] Lustre: 109732:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3472.036871] Lustre: 109732:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 251 previous similar messages [ 3473.051908] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3482.491154] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 11:53:16 (1785081196) [ 3483.757266] Lustre: 109733:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3483.763320] Lustre: 109733:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 56 previous similar messages [ 3483.768268] Lustre: 109733:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 3483.772315] Lustre: 109733:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 50 previous similar messages [ 3483.779284] Lustre: 109733:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3483.784253] Lustre: 109733:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 50 previous similar messages [ 3483.788485] Lustre: 109733:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3483.793266] Lustre: 109733:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 3483.803553] Lustre: 109733:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3483.809317] Lustre: 109733:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 3483.815243] Lustre: 109733:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3483.819402] Lustre: 109733:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 3484.792029] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3488.859180] Lustre: 111653:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3488.874778] Lustre: 111653:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3488.887817] Lustre: 111653:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3488.898378] Lustre: 111653:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3488.909837] Lustre: 111653:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3488.922641] Lustre: 111653:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3488.938177] Lustre: 111653:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3488.949728] Lustre: 111653:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3488.960489] Lustre: 111653:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3488.968470] Lustre: 111653:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3488.978523] Lustre: 111653:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3488.986631] Lustre: 111653:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3495.502423] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 11:53:29 (1785081209) [ 3496.972134] Lustre: 111652:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 3496.978248] Lustre: 111652:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 18 previous similar messages [ 3496.982783] Lustre: 111652:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3496.987470] Lustre: 111652:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3496.998178] Lustre: 111652:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 3497.005397] Lustre: 111652:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3497.017194] Lustre: 111652:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3497.031722] Lustre: 111652:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3497.036680] Lustre: 111652:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3497.042591] Lustre: 111652:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3497.048669] Lustre: 111652:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3497.053319] Lustre: 111652:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3498.529394] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3498.531213] Lustre: Skipped 1 previous similar message [ 3499.579723] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3499.589722] Lustre: Skipped 1 previous similar message [ 3514.853499] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3516.113996] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 11:53:50 (1785081230) [ 3516.474628] Lustre: 112041:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3516.484456] Lustre: 112041:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 4 previous similar messages [ 3516.492671] Lustre: 112041:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3516.502818] Lustre: 112041:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3516.509552] Lustre: 112041:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3516.514939] Lustre: 112041:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3516.520656] Lustre: 112041:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3516.525771] Lustre: 112041:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3516.530425] Lustre: 112041:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3516.535073] Lustre: 112041:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3516.539609] Lustre: 112041:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3516.544168] Lustre: 112041:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3518.514971] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3518.636039] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3520.433914] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3520.435980] Lustre: Skipped 3 previous similar messages [ 3539.490393] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 11:54:13 (1785081253) [ 3542.424749] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3542.435438] Lustre: Skipped 5 previous similar messages [ 3575.268639] 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 [ 3575.274811] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3575.294222] Lustre: Skipped 1 previous similar message [ 3575.300749] Lustre: Skipped 3 previous similar messages [ 3580.389200] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3580.396686] Lustre: Skipped 3 previous similar messages [ 3581.488777] Lustre: server umount lustre-MDT0000 complete [ 3584.986384] LustreError: 111662:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785081300 with bad export cookie 17142746701913517214 [ 3584.990939] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3584.992679] LustreError: 111662:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3585.309750] Lustre: server umount lustre-MDT0001 complete [ 3599.098416] Lustre: server umount lustre-OST0000 complete [ 3601.881897] Lustre: 106886:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785081300/real 1785081300] req@ffff909b36ea7b80 x1871793127366016/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785081316 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3601.910107] 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 [ 3601.923780] Lustre: Skipped 2 previous similar messages [ 3602.809048] Lustre: server umount lustre-OST0001 complete [ 3617.967811] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 3627.908462] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3628.368513] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3632.606207] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3633.635328] LustreError: 118394:0:(ldlm_lib.c:1192: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. [ 3633.652411] LustreError: 118394:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 3638.761480] LustreError: 118393:0:(ldlm_lib.c:1192: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. [ 3641.001025] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3641.295759] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3646.227950] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3649.296352] Lustre: 119531:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3655.545694] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3661.379456] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3666.082904] LustreError: 119885:0:(ldlm_lib.c:1192: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. [ 3666.101504] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3669.573179] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3669.702829] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3669.709918] Lustre: Skipped 1 previous similar message [ 3673.840704] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3673.845850] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3673.884950] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3677.199134] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3684.938594] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3688.156629] Lustre: 121404:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3701.336362] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 11:56:55 (1785081415) [ 3701.605820] Lustre: 119653:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3701.621082] Lustre: 119653:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 46 previous similar messages [ 3701.637365] Lustre: 119653:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3701.656360] Lustre: 119653:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3701.668052] Lustre: 119653:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3701.676438] Lustre: 119653:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3701.694798] Lustre: 119653:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 3701.718827] Lustre: 119653:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3701.735317] Lustre: 119653:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3701.747696] Lustre: 119653:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3701.755687] Lustre: 119653:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3701.760559] Lustre: 119653:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3703.244297] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3703.248397] Lustre: Skipped 3 previous similar messages [ 3738.592910] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3738.605599] 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 [ 3738.623083] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3740.641825] 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 [ 3740.643350] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3740.664204] Lustre: Skipped 2 previous similar messages [ 3740.699163] Lustre: Skipped 3 previous similar messages [ 3743.519797] Lustre: server umount lustre-MDT0000 complete [ 3745.767872] LustreError: 118393:0:(ldlm_lib.c:1192: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. [ 3745.801403] LustreError: 118393:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 3747.013637] LustreError: 118374:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785081462 with bad export cookie 17142746701913532460 [ 3747.019273] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3747.032739] LustreError: 118374:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3747.667492] Lustre: server umount lustre-MDT0001 complete [ 3761.719806] Lustre: server umount lustre-OST0000 complete [ 3775.173763] Lustre: server umount lustre-OST0001 complete [ 3790.506408] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 3800.118607] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3800.482655] LustreError: 123974:0:(ldlm_lib.c:1192: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. [ 3800.543042] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3805.172377] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3810.793116] LustreError: 123975:0:(ldlm_lib.c:1192: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. [ 3810.809309] LustreError: 123975:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 3813.496494] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3817.765129] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3820.140137] Lustre: 125114:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3826.147435] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3832.413715] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3838.753614] LustreError: 125467:0:(ldlm_lib.c:1192: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. [ 3838.763226] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3840.998515] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3845.350144] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3845.366612] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3845.383725] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3847.323477] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3854.663509] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3858.857473] Lustre: 126986:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3864.278849] Lustre: 123974:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3864.285274] Lustre: 123974:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3864.289990] Lustre: 123974:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3864.293931] Lustre: 123974:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3864.298834] Lustre: 123974:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3864.301707] Lustre: 123974:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3864.306043] Lustre: 123974:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3864.309872] Lustre: 123974:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3864.313755] Lustre: 123974:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3864.318486] Lustre: 123974:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3864.322842] Lustre: 123974:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3864.326844] Lustre: 123974:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3864.360605] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3864.365310] Lustre: Skipped 1 previous similar message [ 3890.822291] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 12:00:04 (1785081604) [ 3893.592119] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3893.594154] Lustre: Skipped 3 previous similar messages [ 3899.863029] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3899.869192] Lustre: Skipped 1 previous similar message [ 3917.204381] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 12:00:30 (1785081630) [ 3919.448653] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3931.071558] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 12:00:45 (1785081645) [ 3934.986676] Lustre: *** cfs_fail_loc=162f, val=0*** [ 3934.989669] Lustre: Skipped 9 previous similar messages [ 3948.657879] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 12:01:02 (1785081662) [ 3960.125328] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 12:01:14 (1785081674) [ 3962.925608] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3962.965989] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3962.971289] Lustre: Skipped 3 previous similar messages [ 3968.320627] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.203.41@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:202 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 3969.470419] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.203.41@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 3976.332993] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 12:01:30 (1785081690) [ 3993.054064] Lustre: 128045:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 3993.061670] Lustre: 128045:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 134 previous similar messages [ 3993.067316] Lustre: 128045:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3993.075665] Lustre: 128045:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3993.081850] Lustre: 128045:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 3993.086842] Lustre: 128045:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3993.093027] Lustre: 128045:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3993.100204] Lustre: 128045:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3993.104648] Lustre: 128045:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3993.108875] Lustre: 128045:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3993.113418] Lustre: 128045:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3993.118234] Lustre: 128045:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3999.828993] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 12:01:53 (1785081713) [ 4005.846096] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 12:01:59 (1785081719) [ 4018.474637] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 12:02:12 (1785081732) [ 4021.113901] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4021.134798] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4021.143177] Lustre: Skipped 1 previous similar message [ 4032.309449] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 12:02:26 (1785081746) [ 4033.696848] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4033.703924] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4044.633221] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 12:02:38 (1785081758) [ 4046.277900] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4059.485704] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4060.920132] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 12:02:55 (1785081775) [ 4066.681991] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4066.687189] Lustre: Skipped 1 previous similar message [ 4069.016747] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4090.935398] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 12:03:25 (1785081805) [ 4092.923326] Lustre: Failing over lustre-MDT0000 [ 4093.239992] Lustre: server umount lustre-MDT0000 complete [ 4093.342524] LustreError: 123969:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.41@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4095.466281] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4095.481875] 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 [ 4101.985284] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4102.072987] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4102.311904] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4102.320113] Lustre: Skipped 3 previous similar messages [ 4102.370226] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4103.554149] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4106.731622] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4107.752408] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4107.816721] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4107.887096] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4107.897027] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4108.752781] LustreError: 123969:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4118.671604] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 12:03:52 (1785081832) [ 4120.321578] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4120.454169] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4120.457864] Lustre: Skipped 1 previous similar message [ 4129.828462] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 12:04:03 (1785081843) [ 4131.190897] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4140.611633] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 12:04:14 (1785081854) [ 4141.963170] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4151.200840] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 12:04:25 (1785081865) [ 4161.089207] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 12:04:35 (1785081875) [ 4162.468540] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4162.473172] Lustre: Skipped 1 previous similar message [ 4174.237318] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 12:04:48 (1785081888) [ 4186.204890] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 12:05:00 (1785081900) [ 4192.505771] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4192.515670] Lustre: Skipped 1 previous similar message [ 4207.215768] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 12:05:21 (1785081921) [ 4209.504854] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4209.510552] Lustre: Skipped 4 previous similar messages [ 4220.257905] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 12:05:34 (1785081934) [ 4245.193304] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 12:05:59 (1785081959) [ 4247.472927] LustreError: 123969:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4253.396735] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 12:06:07 (1785081967) [ 4253.679529] Lustre: 126498:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 278, rollback = 2 [ 4253.687451] Lustre: 126498:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 757 previous similar messages [ 4253.693559] Lustre: 126498:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4253.699328] Lustre: 126498:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 757 previous similar messages [ 4253.710847] Lustre: 126498:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4253.719756] Lustre: 126498:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 757 previous similar messages [ 4253.726306] Lustre: 126498:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 4253.731710] Lustre: 126498:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 757 previous similar messages [ 4253.742858] Lustre: 126498:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4253.748470] Lustre: 126498:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 757 previous similar messages [ 4253.754582] Lustre: 126498:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4253.761282] Lustre: 126498:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 757 previous similar messages [ 4278.564189] Lustre: Failing over lustre-MDT0000 [ 4278.897238] Lustre: server umount lustre-MDT0000 complete [ 4281.824944] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4281.827818] 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 [ 4281.837819] LustreError: 126498:0:(ldlm_lib.c:1192: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. [ 4281.837831] LustreError: 126498:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 10 previous similar messages [ 4281.914279] Lustre: Skipped 6 previous similar messages [ 4289.708147] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4289.872317] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4290.169402] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4290.217379] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4294.726515] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4295.659217] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4295.663666] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4295.677855] Lustre: Skipped 3 previous similar messages [ 4295.691294] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4295.753175] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 4295.758079] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 4305.951102] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 12:06:59 (1785082019) [ 4318.496314] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 12:07:12 (1785082032) [ 4332.030994] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 12:07:26 (1785082046) [ 4333.319561] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4333.325718] Lustre: Skipped 7 previous similar messages [ 4345.713581] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 12:07:39 (1785082059) [ 4351.383890] Lustre: Failing over lustre-MDT0000 [ 4351.617741] Lustre: server umount lustre-MDT0000 complete [ 4351.968704] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4351.978472] 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 [ 4352.005897] Lustre: Skipped 3 previous similar messages [ 4359.677984] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4359.790505] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4360.106257] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4364.812674] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4365.284561] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4365.307868] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4365.326272] Lustre: Skipped 3 previous similar messages [ 4365.382420] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4365.425671] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 4365.427670] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 4374.773630] Lustre: Failing over lustre-MDT0000 [ 4375.157725] Lustre: server umount lustre-MDT0000 complete [ 4375.532387] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4383.609218] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4383.757092] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4384.167589] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4387.200483] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4389.008716] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4389.361563] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4389.366435] Lustre: Skipped 3 previous similar messages [ 4389.383882] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4389.437971] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:257) [ 4389.449352] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 4397.616490] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 12:08:31 (1785082111) [ 4409.017234] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 12:08:43 (1785082123) [ 4420.122197] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 12:08:53 (1785082133) [ 4458.836391] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 12:09:32 (1785082172) [ 4473.971335] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 12:09:47 (1785082187) [ 4482.371883] LustreError: 148380:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4484.482377] Lustre: Failing over lustre-OST0000 [ 4484.617259] Lustre: server umount lustre-OST0000 complete [ 4485.425061] LustreError: 148380:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4485.433362] LustreError: 148380:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4486.626055] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4486.630460] LustreError: 125470:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4486.648851] Lustre: Skipped 5 previous similar messages [ 4486.660507] LustreError: 125470:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 25 previous similar messages [ 4487.142146] LustreError: 148380:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4499.227245] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4499.500675] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4501.092370] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4501.121425] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4501.123088] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4501.127316] Lustre: Skipped 3 previous similar messages [ 4506.266664] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4514.961909] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 12:10:28 (1785082228) [ 4530.093662] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 4549.692606] Lustre: 151184:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4571.697725] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4575.137631] Lustre: 152318:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4586.114652] LustreError: 152435:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4588.613399] Lustre: Failing over lustre-MDT0001 [ 4589.025531] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 4589.038258] 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 [ 4589.051417] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4589.152677] LustreError: 152435:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4589.179831] LustreError: 152434:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4589.205419] LustreError: 152434:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4589.616042] Lustre: server umount lustre-MDT0001 complete [ 4592.281079] LustreError: 152434:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4592.293138] LustreError: 152434:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4603.519305] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4603.904700] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4603.911468] Lustre: Skipped 3 previous similar messages [ 4603.955261] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4608.017281] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4608.995709] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4609.001020] Lustre: Skipped 1 previous similar message [ 4609.003686] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4609.014573] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4609.067231] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 4609.067241] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 4615.432760] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 12:12:09 (1785082329) [ 4628.480473] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 4645.146179] Lustre: 155153:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4666.746914] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4670.366965] Lustre: 156288:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4689.752718] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 12:13:23 (1785082403) [ 4691.679383] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 4693.423188] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 12:13:27 (1785082407) [ 4700.463669] Lustre: *** cfs_fail_loc=1631, val=0*** [ 4710.423822] LustreError: 125116:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785082425 with bad export cookie 17142746701913634135 [ 4710.447277] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4710.676777] Lustre: server umount lustre-MDT0000 complete [ 4714.280115] LustreError: 123956:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785082429 with bad export cookie 17142746701913605337 [ 4714.283686] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4714.296332] LustreError: 123956:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4714.650224] Lustre: server umount lustre-MDT0001 complete [ 4728.631511] Lustre: server umount lustre-OST0000 complete [ 4742.477312] Lustre: server umount lustre-OST0001 complete [ 4756.155473] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 4767.187977] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4767.948499] LustreError: 159059:0:(ldlm_lib.c:1192: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. [ 4767.986360] LustreError: 159059:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 18 previous similar messages [ 4774.529918] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4785.012697] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4789.975370] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4793.066979] Lustre: 160200:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4799.929198] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4805.894876] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4810.553263] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 4813.006419] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4814.195433] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4814.198132] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 4814.200482] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4818.410477] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4825.413787] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4828.819196] Lustre: 162072:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4837.487362] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 12:15:51 (1785082551) [ 4838.784732] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4840.335049] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 12:15:54 (1785082554) [ 4841.657582] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4843.337993] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 12:15:57 (1785082557) [ 4844.611525] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4846.149894] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 12:16:00 (1785082560) [ 4847.534607] Lustre: 161886:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 4847.545730] Lustre: 161886:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1654 previous similar messages [ 4847.552611] Lustre: 161886:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4847.561384] Lustre: 161886:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1654 previous similar messages [ 4847.566852] Lustre: 161886:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4847.580522] Lustre: 161886:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1654 previous similar messages [ 4847.588500] Lustre: 161886:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4847.593532] Lustre: 161886:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1654 previous similar messages [ 4847.598925] Lustre: 161886:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4847.602593] Lustre: 161886:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1654 previous similar messages [ 4847.609937] Lustre: 161886:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4847.615480] Lustre: 161886:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1654 previous similar messages [ 4856.400327] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 12:16:10 (1785082570) [ 4868.504941] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 12:16:22 (1785082582) [ 4881.162487] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 12:16:35 (1785082595) [ 4895.506264] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 12:16:49 (1785082609) [ 4914.862716] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 12:17:08 (1785082628) [ 4948.395881] Lustre: *** cfs_fail_loc=1632, val=0*** [ 4961.184723] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 12:17:55 (1785082675) [ 4963.949371] Lustre: Failing over lustre-MDT0001 [ 4964.149450] Lustre: server umount lustre-MDT0001 complete [ 4964.838693] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 4964.849859] 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 [ 4964.864355] Lustre: Skipped 6 previous similar messages [ 4970.491789] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4970.791893] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4970.796359] Lustre: lustre-MDT0001: Aborting client recovery [ 4970.799320] LustreError: 165855:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 4970.806109] LustreError: 165878:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 0, retries 0, failed: rc = -108 [ 4970.806505] Lustre: 165879:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4970.824726] Lustre: 165879:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 97c2725c-ca06-4cf7-bd4f-7ad1c7bbfd81@ [ 4970.832916] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 4970.839332] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 4970.848367] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 4970.885462] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 4970.888894] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 4975.961960] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4976.112844] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 4976.152684] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4976.165179] Lustre: Skipped 3 previous similar messages [ 4979.788138] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 4984.090572] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 4984.410833] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 4990.737684] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 12:18:24 (1785082704) [ 5000.639579] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5003.995542] Lustre: Failing over lustre-MDT0000 [ 5004.467474] Lustre: server umount lustre-MDT0000 complete [ 5006.817792] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5014.523566] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5014.678082] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5014.974993] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5014.983331] Lustre: Skipped 2 previous similar messages [ 5016.900247] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5018.313694] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5020.137144] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5020.152322] Lustre: Skipped 1 previous similar message [ 5020.228250] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5020.328141] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5020.330181] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 5028.963222] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 12:19:02 (1785082742) [ 5054.305064] Lustre: Failing over lustre-OST0000 [ 5054.403854] Lustre: server umount lustre-OST0000 complete [ 5060.622975] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5071.071340] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5072.522262] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5073.088709] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5077.952247] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5084.885805] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5085.200164] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5089.925284] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5090.125134] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5095.953860] Lustre: DEBUG MARKER: oleg341-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff905cc4358800.ost_server_uuid 50 [ 5097.416769] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff905cc4358800.ost_server_uuid in FULL state after 0 sec [ 5148.132856] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5148.140238] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5148.148014] Lustre: Skipped 3 previous similar messages [ 5152.024938] Lustre: server umount lustre-MDT0000 complete [ 5160.113440] LustreError: 159039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785082875 with bad export cookie 17142746701913687923 [ 5160.122230] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5160.124397] LustreError: 159039:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5160.430362] Lustre: server umount lustre-MDT0001 complete [ 5179.617732] Lustre: 106885:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785082878/real 1785082878] req@ffff909a0ae13480 x1871793129156224/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785082894 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5180.895840] Lustre: server umount lustre-OST0000 complete [ 5181.920242] Lustre: 106886:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785082880/real 1785082880] req@ffff909a0ae11f80 x1871793129156608/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785082896 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5184.737182] Lustre: 106885:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785082883/real 1785082883] req@ffff909a0ae10700 x1871793129156864/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785082899 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5186.848129] Lustre: 106885:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785082885/real 1785082885] req@ffff909b1da0ea00 x1871793129157632/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785082901 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5186.886366] Lustre: 106885:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5189.416716] Lustre: server umount lustre-OST0001 complete [ 5206.965670] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing unload_modules_local [ 5209.745580] Key type lgssc unregistered [ 5210.067986] LNet: 174987:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5210.078255] LNetError: 174987:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5210.094156] LNet: Removed LNI 192.168.203.141@tcp [ 5211.001154] Key type .llcrypt unregistered [ 5211.002916] Key type ._llcrypt unregistered [ 5233.711916] Key type ._llcrypt registered [ 5233.714618] Key type .llcrypt registered [ 5233.893824] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_hostid [ 5250.893131] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 5251.945449] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5251.969745] alg: No test for adler32 (adler32-zlib) [ 5253.163633] Lustre: Lustre: Build Version: 2.17.54_162_gf7f7620 [ 5253.568899] LNet: Added LNI 192.168.203.141@tcp [8/256/0/180] [ 5255.320159] Key type lgssc registered [ 5256.712352] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5309.311157] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing load_modules_local [ 5322.294192] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 5322.314927] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5323.620110] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5323.646526] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5323.714081] Lustre: lustre-MDT0000: new disk, initializing [ 5323.782545] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5323.807962] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5328.044397] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5340.514612] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5340.618933] Lustre: 179442: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 [ 5340.649981] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5340.654875] Lustre: Skipped 1 previous similar message [ 5340.752885] Lustre: lustre-MDT0001: new disk, initializing [ 5340.820866] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5340.851424] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5340.863403] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5345.037686] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5349.587301] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5358.353428] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5358.638409] Lustre: lustre-OST0000: new disk, initializing [ 5358.646704] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5358.658099] Lustre: 181383:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5358.733044] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5364.537404] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5364.778417] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5364.793906] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5364.832147] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5376.871639] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5376.968607] Lustre: lustre-OST0001: new disk, initializing [ 5376.972872] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5376.976969] Lustre: 182404:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5377.041764] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5383.212455] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5384.727268] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5384.735936] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5384.817723] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5393.808855] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5398.886673] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5404.135435] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 12:25:17 (1785083117) === [ 5405.784651] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5122 sec ========= 12:25:19 (1785083119) [ 5407.373103] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 12:25:21 (1785083121) === [ 5410.353550] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 12:25:24 (1785083124) === [ 5415.394527] 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 [ 5415.400664] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5415.403575] Lustre: Skipped 3 previous similar messages [ 5415.417776] Lustre: Skipped 3 previous similar messages [ 5420.122795] Lustre: server umount lustre-MDT0000 complete [ 5425.633906] LustreError: 179448:0:(ldlm_lib.c:1192: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. [ 5425.651906] LustreError: 179448:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 5427.526360] LustreError: 183172:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1785083142 with bad export cookie 8413797476091310706 [ 5427.529125] LustreError: MGC192.168.203.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5427.535772] LustreError: 183172:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5427.903463] Lustre: server umount lustre-MDT0001 complete [ 5445.311264] Lustre: server umount lustre-OST0000 complete [ 5445.986456] Lustre: 176602:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785083145/real 1785083145] req@ffff909b37560000 x1871795158333824/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785083161 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5446.025712] 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 [ 5448.161235] Lustre: 176603:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785083147/real 1785083147] req@ffff909a0b510a80 x1871795158334080/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785083163 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5451.168112] Lustre: 176602:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785083150/real 1785083150] req@ffff909a0b510000 x1871795158334336/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785083166 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5453.280155] Lustre: 176601:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1785083152/real 1785083152] req@ffff909a0b386680 x1871795158334720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1785083168 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5453.826559] Lustre: server umount lustre-OST0001 complete [ 5470.073958] Lustre: DEBUG MARKER: oleg341-server.virtnet: executing unload_modules_local [ 5472.652870] Key type lgssc unregistered [ 5472.930814] LNet: 185877:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5472.940859] LNetError: 185877:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5472.954065] LNet: Removed LNI 192.168.203.141@tcp [ 5473.869526] Key type .llcrypt unregistered [ 5473.875107] Key type ._llcrypt unregistered