[ 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 455913927 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K 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.002364] x2apic enabled [ 0.003010] Switched APIC routing to physical x2apic. [ 0.004013] kvm-guest: setup PV IPIs [ 0.006618] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007021] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008017] pid_max: default: 32768 minimum: 301 [ 0.009156] LSM: Security Framework initializing [ 0.010056] Yama: becoming mindful. [ 0.011034] SELinux: Initializing. [ 0.012071] *** VALIDATE selinux *** [ 0.020287] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025354] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026191] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027120] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028106] *** VALIDATE tmpfs *** [ 0.030265] *** VALIDATE proc *** [ 0.032134] *** VALIDATE cgroup *** [ 0.033009] *** VALIDATE cgroup2 *** [ 0.035102] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036179] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038033] Spectre V2 : User space: Vulnerable [ 0.039011] Speculative Store Bypass: Vulnerable [ 0.042798] debug: unmapping init [mem 0xffffffff92859000-0xffffffff92860fff] [ 0.045165] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046690] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047024] ... version: 2 [ 0.048014] ... bit width: 48 [ 0.049014] ... generic registers: 4 [ 0.050013] ... value mask: 0000ffffffffffff [ 0.051018] ... max period: 00007fffffffffff [ 0.052008] ... fixed-purpose events: 3 [ 0.052937] ... event mask: 000000070000000f [ 0.053310] rcu: Hierarchical SRCU implementation. [ 0.055483] smp: Bringing up secondary CPUs ... [ 0.056556] x86: Booting SMP configuration: [ 0.057025] .... node #0, CPUs: #1 #2 #3 [ 0.060714] smp: Brought up 1 node, 4 CPUs [ 0.062014] smpboot: Max logical packages: 1 [ 0.063014] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.137872] node 0 deferred pages initialised in 72ms [ 0.142174] devtmpfs: initialized [ 0.144182] x86/mm: Memory block size: 128MB [ 0.146777] gcov: version magic: 0x41383552 [ 0.149194] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.153075] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.156276] pinctrl core: initialized pinctrl subsystem [ 0.158173] [ 0.158779] ************************************************************* [ 0.161011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.163011] ** ** [ 0.165012] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.167010] ** ** [ 0.172018] ** This means that this kernel is built to expose internal ** [ 0.174009] ** IOMMU data structures, which may compromise security on ** [ 0.180013] ** your system. ** [ 0.182011] ** ** [ 0.184010] ** If you see this message and you are not debugging the ** [ 0.186012] ** kernel, report this immediately to your vendor! ** [ 0.188012] ** ** [ 0.190010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.193012] ************************************************************* [ 0.196674] NET: Registered protocol family 16 [ 0.198390] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.200050] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.203050] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.207095] cpuidle: using governor menu [ 0.208864] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.211481] PCI: Using configuration type 1 for base access [ 0.213118] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.221106] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.224037] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.227159] cryptd: max_cpu_qlen set to 1000 [ 0.229245] ACPI: Added _OSI(Module Device) [ 0.231027] ACPI: Added _OSI(Processor Device) [ 0.232012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.234012] ACPI: Added _OSI(Processor Aggregator Device) [ 0.238945] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.244311] ACPI: Interpreter enabled [ 0.246050] ACPI: PM: (supports S0 S3 S4 S5) [ 0.247017] ACPI: Using IOAPIC for interrupt routing [ 0.249091] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.252302] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.261000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.263028] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.265014] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.268058] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.273271] acpiphp: Slot [2] registered [ 0.275148] acpiphp: Slot [5] registered [ 0.276111] acpiphp: Slot [6] registered [ 0.277095] acpiphp: Slot [7] registered [ 0.279143] acpiphp: Slot [8] registered [ 0.281089] acpiphp: Slot [9] registered [ 0.282173] acpiphp: Slot [10] registered [ 0.283121] acpiphp: Slot [3] registered [ 0.285085] acpiphp: Slot [4] registered [ 0.286080] acpiphp: Slot [11] registered [ 0.288095] acpiphp: Slot [12] registered [ 0.289080] acpiphp: Slot [13] registered [ 0.290085] acpiphp: Slot [14] registered [ 0.292087] acpiphp: Slot [15] registered [ 0.293091] acpiphp: Slot [16] registered [ 0.295110] acpiphp: Slot [17] registered [ 0.297102] acpiphp: Slot [18] registered [ 0.298114] acpiphp: Slot [19] registered [ 0.300082] acpiphp: Slot [20] registered [ 0.301105] acpiphp: Slot [21] registered [ 0.302087] acpiphp: Slot [22] registered [ 0.304118] acpiphp: Slot [23] registered [ 0.305075] acpiphp: Slot [24] registered [ 0.307089] acpiphp: Slot [25] registered [ 0.308084] acpiphp: Slot [26] registered [ 0.309097] acpiphp: Slot [27] registered [ 0.310068] acpiphp: Slot [28] registered [ 0.312086] acpiphp: Slot [29] registered [ 0.313070] acpiphp: Slot [30] registered [ 0.314079] acpiphp: Slot [31] registered [ 0.316058] PCI host bridge to bus 0000:00 [ 0.317023] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.320020] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.323021] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.326021] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.328021] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.332013] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.333132] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.335958] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.340144] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.349684] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.355040] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.357017] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.360019] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.362020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.364415] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.367817] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.371047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.374749] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.380010] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.391015] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.395992] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.401738] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.408024] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.414017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.427019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.441633] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.448017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.456015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.474010] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.485208] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.489020] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.494021] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.507023] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.515046] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.522019] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.527013] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.547012] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.556000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.564015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.570017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.590018] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.600013] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.607014] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.615017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.637017] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.649297] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.651363] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.653329] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.655385] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.658202] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.662115] iommu: Default domain type: Passthrough [ 0.664375] SCSI subsystem initialized [ 0.665143] ACPI: bus type USB registered [ 0.667122] usbcore: registered new interface driver usbfs [ 0.669088] usbcore: registered new interface driver hub [ 0.671078] usbcore: registered new device driver usb [ 0.673171] pps_core: LinuxPPS API ver. 1 registered [ 0.675012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.678064] PTP clock support registered [ 0.680077] EDAC MC: Ver: 3.0.0 [ 0.682135] PCI: Using ACPI for IRQ routing [ 0.683990] NetLabel: Initializing [ 0.684010] NetLabel: domain hash size = 128 [ 0.685012] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.686120] NetLabel: unlabeled traffic allowed by default [ 0.689050] vgaarb: loaded [ 0.690280] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.692011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.696250] clocksource: Switched to clocksource kvm-clock [ 0.796815] VFS: Disk quotas dquot_6.6.0 [ 0.798534] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.800537] *** VALIDATE ramfs *** [ 0.801721] *** VALIDATE hugetlbfs *** [ 0.803091] pnp: PnP ACPI init [ 0.804921] pnp: PnP ACPI: found 6 devices [ 0.823439] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.826721] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.829029] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.831282] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.833696] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.835954] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.838647] NET: Registered protocol family 2 [ 0.840920] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.844653] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.848029] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.853511] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.857274] TCP: Hash tables configured (established 65536 bind 65536) [ 0.860146] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.863179] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.865989] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.869312] NET: Registered protocol family 1 [ 0.872621] RPC: Registered named UNIX socket transport module. [ 0.875534] RPC: Registered udp transport module. [ 0.877134] RPC: Registered tcp transport module. [ 0.878704] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.881196] NET: Registered protocol family 44 [ 0.882450] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.883953] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.886227] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.888802] PCI: CLS 0 bytes, default 64 [ 0.890462] Unpacking initramfs... [ 2.259731] debug: unmapping init [mem 0xffff8de67cc54000-0xffff8de67ffbffff] [ 2.263947] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.266062] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.269287] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.756250] Initialise system trusted keyrings [ 2.758074] Key type blacklist registered [ 2.760132] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.768315] zbud: loaded [ 2.773284] *** VALIDATE nfs *** [ 2.774655] *** VALIDATE nfs4 *** [ 2.777688] pstore: using deflate compression [ 2.781546] Platform Keyring initialized [ 2.885538] NET: Registered protocol family 38 [ 2.887273] Key type asymmetric registered [ 2.888567] Asymmetric key parser 'x509' registered [ 2.890119] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.893031] io scheduler mq-deadline registered [ 2.894463] io scheduler kyber registered [ 2.895904] io scheduler bfq registered [ 2.897863] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.900578] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.904077] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.907476] ACPI: Power Button [PWRF] [ 2.914582] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.921871] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.936780] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.949659] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.964164] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.990908] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.019549] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.025216] Non-volatile memory driver v1.3 [ 3.026691] Linux agpgart interface v0.103 [ 3.054721] virtio_blk virtio1: [vda] 136552 512-byte logical blocks (69.9 MB/66.7 MiB) [ 3.057366] vda: detected capacity change from 0 to 69914624 [ 3.069992] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.072461] vdb: detected capacity change from 0 to 1073741824 [ 3.084845] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.087324] vdc: detected capacity change from 0 to 2621440000 [ 3.099457] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.101805] vdd: detected capacity change from 0 to 2621440000 [ 3.113841] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.116516] vde: detected capacity change from 0 to 4294967296 [ 3.129442] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.132387] vdf: detected capacity change from 0 to 4294967296 [ 3.137876] libphy: Fixed MDIO Bus: probed [ 3.143470] usbcore: registered new interface driver usbserial_generic [ 3.146422] usbserial: USB Serial support registered for generic [ 3.149317] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.154602] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.156867] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.160448] mousedev: PS/2 mouse device common for all mice [ 3.162865] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.165384] rtc_cmos 00:05: RTC can wake from S4 [ 3.168958] rtc_cmos 00:05: registered as rtc0 [ 3.170849] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.172450] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.174105] intel_pstate: CPU model not supported [ 3.179191] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.180145] hid: raw HID events driver (C) Jiri Kosina [ 3.184649] usbcore: registered new interface driver usbhid [ 3.186705] usbhid: USB HID core driver [ 3.188218] drop_monitor: Initializing network drop monitor service [ 3.190768] Initializing XFRM netlink socket [ 3.192441] NET: Registered protocol family 10 [ 3.195042] Segment Routing with IPv6 [ 3.196665] NET: Registered protocol family 17 [ 3.198738] mpls_gso: MPLS GSO support [ 3.204495] RAS: Correctable Errors collector initialized. [ 3.206778] AVX version of gcm_enc/dec engaged. [ 3.208697] AES CTR mode by8 optimization enabled [ 3.286046] sched_clock: Marking stable (3286011979, 0)->(4158240634, -872228655) [ 3.289627] registered taskstats version 1 [ 3.291983] Loading compiled-in X.509 certificates [ 3.293665] zswap: loaded using pool lzo/zbud [ 3.316382] Key type big_key registered [ 3.328706] Key type encrypted registered [ 3.330301] ima: No TPM chip found, activating TPM-bypass! [ 3.332213] ima: Allocated hash algorithm: sha1 [ 3.333832] ima: No architecture policies found [ 3.335580] evm: Initialising EVM extended attributes: [ 3.337493] evm: security.selinux [ 3.338686] evm: security.ima [ 3.339835] evm: security.capability [ 3.341270] evm: HMAC attrs: 0x1 [ 3.343515] rtc_cmos 00:05: setting system clock to 2026-06-11 22:13:38 UTC (1781216018) [ 3.349664] debug: unmapping init [mem 0xffffffff93803000-0xffffffff939fffff] [ 3.352697] debug: unmapping init [mem 0xffffffff92582000-0xffffffff92858fff] [ 3.359239] Write protecting the kernel read-only data: 28672k [ 3.362843] debug: unmapping init [mem 0xffffffff90c03000-0xffffffff90dfffff] [ 3.366383] debug: unmapping init [mem 0xffffffff91514000-0xffffffff915fffff] [ 3.406239] 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.415431] systemd[1]: Detected virtualization kvm. [ 3.417109] systemd[1]: Detected architecture x86-64. [ 3.419505] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.443635] systemd[1]: No hostname configured. [ 3.445330] systemd[1]: Set hostname to . [ 3.447517] random: systemd: uninitialized urandom read (16 bytes read) [ 3.450261] systemd[1]: Initializing machine ID from random generator. [ 3.513927] random: ln: uninitialized urandom read (6 bytes read) [ 3.598194] random: systemd: uninitialized urandom read (16 bytes read) [ 3.601437] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.607639] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.612044] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ OK ] Reached target Timers. [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Sockets. Starting Apply Kernel Variables... Starting Journal Service... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Setup Virtual Console... [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.226614] device-mapper: uevent: version 1.0.3 [ 4.228434] 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... [ 4.948553] random: fast init done [ 4.995807] virtio_net virtio0 ens2: renamed from eth0 [ 5.020463] scsi host0: ata_piix [ 5.033279] scsi host1: ata_piix [ 5.034837] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.038567] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.719830] dracut-initqueue[581]: RTNETLINK answers: File exists [ 9.845913] random: crng init done [ 9.846866] 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. [ 10.272273] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Timers. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Create Volatile Files and Directories. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.358675] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.637868] SELinux: Disabled at runtime. [ 11.698466] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 11.708795] systemd[1]: Detected virtualization kvm. [ 11.710783] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.201453] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.204598] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.208703] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.212271] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.214647] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.224469] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.228427] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on initctl Compatibility Named Pipe. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-getty.slice. [ OK ] Listening on udev Control Socket. [ OK ] Created slic[ 12.273876] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS e system-serial\x2dgetty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Listening on Process Core Dump Socket. Starting Apply Kernel Variables... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target Paths. Mounting POSIX Message Queue File System... Starting Create list of required st…ce nodes for the current kernel... Starting Remount Root and Kernel File Systems... [ OK ] Reached target Slices. Mounting Huge Pages File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Mounting Kernel Debug File System... [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ 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 ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 12.648574] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Coldplug all Devices. [ OK ] Started udev Kernel Device Manager. [ 12.966918] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.073107] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.184616] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.196240] EDAC sbridge: Ver: 1.1.2 [ 14.832465] Key type dns_resolver registered [ 15.140096] NFS: Registering the id_resolver key type [ 15.141971] Key type id_resolver registered [ 15.143360] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started D-Bus System Message Bus. [ OK ] Started irqbalance daemon. Starting Network Manager... [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg610-server login: [ 39.915931] libcfs: loading out-of-tree module taints kernel. [ 39.939882] Key type ._llcrypt registered [ 39.941630] Key type .llcrypt registered [ 40.005294] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_hostid [ 49.767721] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 50.552933] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 50.563540] alg: No test for adler32 (adler32-zlib) [ 51.691207] Lustre: Lustre: Build Version: 2.17.53_75_g2ada427 [ 52.103641] LNet: Added LNI 192.168.206.110@tcp [8/256/0/180] [ 53.751160] Key type lgssc registered [ 54.651533] Lustre: Echo OBD driver; http://www.lustre.org/ [ 63.217407] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 81.684177] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 87.889794] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 87.907804] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 89.065804] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 89.084327] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 89.139311] Lustre: lustre-MDT0000: new disk, initializing [ 89.191579] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 89.202486] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 91.137167] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 97.506435] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 97.564885] Lustre: 6473:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 97.591521] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 97.594914] Lustre: Skipped 1 previous similar message [ 97.638870] Lustre: lustre-MDT0001: new disk, initializing [ 97.680746] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 97.702273] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 97.708669] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 99.322311] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 101.993909] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 106.206633] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 106.307440] Lustre: lustre-OST0000: new disk, initializing [ 106.309330] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 106.312441] Lustre: 8379:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 106.338100] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 108.828638] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 113.148321] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 113.154218] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 113.189684] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 115.595428] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 115.653583] Lustre: lustre-OST0001: new disk, initializing [ 115.655835] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 115.659818] Lustre: 9432:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 115.695766] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 118.252428] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 120.306184] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 120.311494] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 120.333218] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 125.259902] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 131.564590] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 133.992849] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing check_logdir /tmp/testlogs/ [ 135.758080] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing yml_node [ 137.650159] Lustre: DEBUG MARKER: Client: 2.17.53.75 [ 138.840331] Lustre: DEBUG MARKER: MDS: 2.17.53.75 [ 140.067833] Lustre: DEBUG MARKER: OSS: 2.17.53.75 [ 140.957880] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Thu Jun 11 18:15:55 EDT 2026 [ 149.697212] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 154.245578] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 159.199867] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 159.204165] 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 [ 159.209754] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 161.249690] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 161.251162] 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 [ 161.261504] Lustre: Skipped 1 previous similar message [ 163.710565] Lustre: server umount lustre-MDT0000 complete [ 167.353538] LustreError: 6463:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781216182 with bad export cookie 220634224459274001 [ 167.355843] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 167.361687] LustreError: 6463:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 167.502602] Lustre: server umount lustre-MDT0001 complete [ 181.123481] Lustre: server umount lustre-OST0000 complete [ 196.394342] Lustre: server umount lustre-OST0001 complete [ 203.604935] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing unload_modules_local [ 205.022623] Key type lgssc unregistered [ 205.206776] LNet: 14661:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 205.211877] LNetError: 14661:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 205.223388] LNet: Removed LNI 192.168.206.110@tcp [ 205.713553] Key type .llcrypt unregistered [ 205.715213] Key type ._llcrypt unregistered [ 218.017452] Key type ._llcrypt registered [ 218.019318] Key type .llcrypt registered [ 218.076913] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_hostid [ 225.612248] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 226.084280] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 226.102913] alg: No test for adler32 (adler32-zlib) [ 226.988650] Lustre: Lustre: Build Version: 2.17.53_75_g2ada427 [ 227.093721] LNet: Added LNI 192.168.206.110@tcp [8/256/0/180] [ 228.687176] Key type lgssc registered [ 229.132265] Lustre: Echo OBD driver; http://www.lustre.org/ [ 249.815466] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 255.315948] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 255.328745] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 256.459397] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 256.490976] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 256.536174] Lustre: lustre-MDT0000: new disk, initializing [ 256.579749] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 256.590796] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 258.322467] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 265.064926] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 265.108768] Lustre: 19037:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 265.132266] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 265.135780] Lustre: Skipped 1 previous similar message [ 265.176645] Lustre: lustre-MDT0001: new disk, initializing [ 265.212497] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 265.226125] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 265.232860] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 267.036346] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 269.915770] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 274.872423] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 274.987495] Lustre: lustre-OST0000: new disk, initializing [ 274.990927] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 274.995924] Lustre: 20940:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 275.022230] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 278.217705] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 280.061954] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 280.068658] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 280.130453] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 284.828425] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 284.886131] Lustre: lustre-OST0001: new disk, initializing [ 284.888764] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 284.893067] Lustre: 21945:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 284.928895] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 287.502551] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 289.017888] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 289.022260] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 289.047768] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 294.684749] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 298.277633] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 302.721489] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 18:18:37 (1781216317) === [ 304.270201] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 18:18:38 (1781216318) [ 304.355501] Lustre: 20948:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 304.361028] Lustre: 20948:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 304.366150] Lustre: 20948:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 304.370572] Lustre: 20948:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 304.375070] Lustre: 20948:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 304.380221] Lustre: 20948:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 304.869717] Lustre: 19042:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 304.875122] Lustre: 19042:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 32 previous similar messages [ 304.878224] Lustre: 19042:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 304.881600] Lustre: 19042:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 304.885147] Lustre: 19042:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 304.888929] Lustre: 19042:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 304.892262] Lustre: 19042:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 304.896149] Lustre: 19042:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 304.899777] Lustre: 19042:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 304.902882] Lustre: 19042:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 304.906092] Lustre: 19042:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 304.909074] Lustre: 19042:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 305.875707] Lustre: 20948:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 305.881705] Lustre: 20948:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 74 previous similar messages [ 305.886267] Lustre: 20948:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 305.891247] Lustre: 20948:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 305.895971] Lustre: 20948:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 305.903374] Lustre: 20948:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 305.910382] Lustre: 20948:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 305.913638] Lustre: 20948:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 305.918016] Lustre: 20948:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 305.922201] Lustre: 20948:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 305.928145] Lustre: 20948:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 305.934214] Lustre: 20948:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 307.889113] Lustre: 19042:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 264, rollback = 2 [ 307.897760] Lustre: 19042:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 131 previous similar messages [ 307.903351] Lustre: 19042:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 307.907917] Lustre: 19042:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 307.913216] Lustre: 19042:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/264/0 [ 307.916726] Lustre: 19042:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 307.923694] Lustre: 19042:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 307.928970] Lustre: 19042:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 307.933608] Lustre: 19042:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 307.937792] Lustre: 19042:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 307.942283] Lustre: 19042:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 307.946734] Lustre: 19042:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 309.301948] Lustre: *** cfs_fail_loc=1600, val=3*** [ 312.061308] Lustre: *** cfs_fail_loc=1600, val=3*** [ 314.825269] Lustre: 20928:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 314.828456] Lustre: 23616:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 314.833537] Lustre: 20928:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 42 previous similar messages [ 314.837764] Lustre: 23616:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 314.837783] Lustre: 23616:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 314.842633] Lustre: 20928:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 314.842643] Lustre: 20928:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 314.842650] Lustre: 20928:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 314.842654] Lustre: 20928:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 314.842660] Lustre: 20928:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 314.842663] Lustre: 20928:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 314.898672] Lustre: 23616:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 56 previous similar messages [ 321.504369] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 321.516082] 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 [ 321.533045] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 325.090976] 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 [ 325.091593] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 325.099481] Lustre: Skipped 1 previous similar message [ 325.102829] Lustre: Skipped 1 previous similar message [ 326.445551] Lustre: server umount lustre-MDT0000 complete [ 328.185766] LustreError: 22695:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781216343 with bad export cookie 13522328243008701574 [ 328.188699] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 328.191947] LustreError: 22695:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 328.316821] Lustre: server umount lustre-MDT0001 complete [ 340.437638] Lustre: server umount lustre-OST0000 complete [ 352.320880] Lustre: server umount lustre-OST0001 complete [ 356.298787] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 18:19:31 (1781216371) [ 362.090941] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 366.000247] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 366.208203] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 367.764615] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 371.385269] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 373.088701] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 374.399407] Lustre: 27082:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 377.843368] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 378.055729] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 378.061512] Lustre: Skipped 1 previous similar message [ 381.062785] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 381.153671] LustreError: 27434:0:(ldlm_lib.c:1179: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. [ 381.164484] LustreError: 27434:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 385.843596] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 389.728510] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 391.080688] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:40 to 0x2c0000401:65) [ 391.080935] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 394.434235] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 396.279385] Lustre: 28915:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 397.286373] Lustre: 25970:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 397.297559] Lustre: 25970:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 63 previous similar messages [ 397.310246] Lustre: 25970:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 397.313227] Lustre: 25970:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 397.317340] Lustre: 25970:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 397.321030] Lustre: 25970:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 397.324256] Lustre: 25970:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 397.328351] Lustre: 25970:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 397.332065] Lustre: 25970:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 397.336089] Lustre: 25970:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 397.340125] Lustre: 25970:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 397.343796] Lustre: 25970:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 400.303281] Lustre: *** cfs_fail_loc=1501, val=0*** [ 403.403030] Lustre: Failing over lustre-MDT0000 [ 403.543034] Lustre: server umount lustre-MDT0000 complete [ 406.495986] 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 [ 406.497702] LustreError: 25971:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 406.504452] Lustre: Skipped 4 previous similar messages [ 406.513401] LustreError: 25971:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 408.739446] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 408.813552] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 408.949410] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 408.952738] Lustre: Skipped 1 previous similar message [ 410.780219] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 411.810150] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 411.820745] Lustre: lustre-MDT0000: Denying connection for new client d0184ecc-429e-4ada-801e-06f65ae50160 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 414.181473] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 414.188128] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 414.209460] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 414.210368] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 417.699345] Lustre: *** cfs_fail_loc=1505, val=0*** [ 421.114448] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 18:20:35 (1781216435) [ 421.742244] Lustre: 30199:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 421.747232] Lustre: 30199:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 322 previous similar messages [ 421.752030] Lustre: 30199:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 421.759832] Lustre: 30199:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 421.764596] Lustre: 30199:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 421.767375] Lustre: 30199:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 421.771650] Lustre: 30199:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 421.777446] Lustre: 30199:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 421.782598] Lustre: 30199:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 421.786597] Lustre: 30199:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 421.790810] Lustre: 30199:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 421.794524] Lustre: 30199:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 424.536331] Lustre: *** cfs_fail_loc=1502, val=0*** [ 428.487047] Lustre: Failing over lustre-MDT0000 [ 428.621507] Lustre: server umount lustre-MDT0000 complete [ 429.535679] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 429.536040] 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 [ 429.543452] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 429.543464] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 429.571277] Lustre: Skipped 3 previous similar messages [ 434.053607] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 434.156255] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 436.204785] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 437.135482] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 437.139391] Lustre: lustre-MDT0000: Denying connection for new client 4148edb7-6ec6-4bd5-9bef-06a983f742d5 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 439.788203] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 439.792893] Lustre: Skipped 3 previous similar messages [ 439.805109] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 439.831059] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 439.831465] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 442.901448] Lustre: *** cfs_fail_loc=1505, val=0*** [ 446.558851] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 18:21:01 (1781216461) [ 450.196758] Lustre: *** cfs_fail_loc=1504, val=0*** [ 450.199346] Lustre: *** cfs_fail_loc=1504, val=0*** [ 450.201058] Lustre: Skipped 1 previous similar message [ 454.070902] Lustre: Failing over lustre-MDT0000 [ 454.174747] Lustre: server umount lustre-MDT0000 complete [ 455.136177] 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 [ 455.137018] LustreError: 25972:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 455.146277] Lustre: Skipped 3 previous similar messages [ 455.159161] LustreError: 25972:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 459.157212] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 459.223825] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 459.361403] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 459.365627] Lustre: Skipped 1 previous similar message [ 461.133435] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 462.233192] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 462.240635] Lustre: lustre-MDT0000: Denying connection for new client b69e5d08-4deb-40a8-b621-9d91910f7686 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 464.355061] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 464.360231] Lustre: Skipped 3 previous similar messages [ 464.369803] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 464.396959] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 464.398593] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 467.979353] Lustre: *** cfs_fail_loc=1505, val=0*** [ 471.424057] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 18:21:26 (1781216486) [ 472.080464] Lustre: 25971:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 472.084950] Lustre: 25971:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 644 previous similar messages [ 472.088043] Lustre: 25971:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 472.091775] Lustre: 25971:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 472.094672] Lustre: 25971:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 472.099491] Lustre: 25971:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 472.103612] Lustre: 25971:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 472.108019] Lustre: 25971:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 472.111827] Lustre: 25971:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 472.115587] Lustre: 25971:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 472.119593] Lustre: 25971:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 472.123316] Lustre: 25971:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 474.645819] Lustre: *** cfs_fail_loc=1603, val=0*** [ 478.150366] Lustre: Failing over lustre-MDT0000 [ 478.271795] Lustre: server umount lustre-MDT0000 complete [ 479.713387] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 479.714989] 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 [ 479.718607] LustreError: 25976:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 479.725044] Lustre: Skipped 2 previous similar messages [ 479.743898] LustreError: 25976:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 483.494272] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 483.551576] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 485.501445] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 486.464159] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 486.467965] Lustre: lustre-MDT0000: Denying connection for new client f1db0476-9b31-4291-927b-b02aeaaf42ae (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 488.932540] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 488.935948] Lustre: Skipped 3 previous similar messages [ 488.953090] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 488.979546] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 488.981636] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 494.727832] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 18:21:49 (1781216509) [ 497.975997] Lustre: *** cfs_fail_loc=1604, val=0*** [ 501.290548] Lustre: Failing over lustre-MDT0000 [ 501.403666] Lustre: server umount lustre-MDT0000 complete [ 504.288133] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 504.288866] 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 [ 504.289631] LustreError: 25976:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 504.304648] Lustre: Skipped 4 previous similar messages [ 507.076308] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 507.141740] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 509.255989] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 510.329235] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 510.335402] Lustre: lustre-MDT0000: Denying connection for new client 21b65430-5cfb-42bc-a26c-9e2cefee5025 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 512.482409] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 512.486028] Lustre: Skipped 3 previous similar messages [ 512.495832] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 512.511560] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 512.511759] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 518.574260] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 18:22:13 (1781216533) [ 521.519121] Lustre: *** cfs_fail_loc=1605, val=0*** [ 524.823995] Lustre: Failing over lustre-MDT0000 [ 524.927839] Lustre: server umount lustre-MDT0000 complete [ 527.840429] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 527.847373] LustreError: 25975:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 527.860882] LustreError: 25975:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 530.208981] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 530.273669] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 530.409312] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 530.413658] Lustre: Skipped 2 previous similar messages [ 532.315504] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 533.566489] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 533.572732] Lustre: lustre-MDT0000: Denying connection for new client ef44c274-5281-4a02-a7da-71f98410b78c (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 535.522971] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 535.531886] Lustre: Skipped 3 previous similar messages [ 535.540200] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 535.565873] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 535.567497] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 541.692979] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 18:22:36 (1781216556) [ 542.387878] Lustre: 26004:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 542.391299] Lustre: 26004:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 968 previous similar messages [ 542.394511] Lustre: 26004:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 542.397848] Lustre: 26004:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 542.401713] Lustre: 26004:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 542.405021] Lustre: 26004:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 542.408733] Lustre: 26004:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 542.412949] Lustre: 26004:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 542.417186] Lustre: 26004:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 542.421240] Lustre: 26004:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 542.424597] Lustre: 26004:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 542.427941] Lustre: 26004:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 545.235139] Lustre: *** cfs_fail_loc=161d, val=0*** [ 548.658981] Lustre: Failing over lustre-MDT0000 [ 548.792656] Lustre: server umount lustre-MDT0000 complete [ 550.879947] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 550.881361] 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 [ 550.890150] Lustre: Skipped 6 previous similar messages [ 553.588572] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 555.664828] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 556.721232] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 556.726200] Lustre: lustre-MDT0000: Denying connection for new client 068d799f-0144-41db-bfec-a2b49a5a7b96 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 559.074476] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 559.081527] Lustre: Skipped 3 previous similar messages [ 559.096042] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 559.114312] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 559.115079] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 565.116743] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 18:22:59 (1781216579) [ 566.218631] Lustre: *** cfs_fail_loc=1603, val=0*** [ 570.720920] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 18:23:05 (1781216585) [ 573.537249] Lustre: *** cfs_fail_loc=1603, val=0*** [ 573.923967] Lustre: *** cfs_fail_loc=1604, val=0*** [ 578.569149] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 18:23:13 (1781216593) [ 611.379423] Lustre: Failing over lustre-MDT0000 [ 611.507299] Lustre: server umount lustre-MDT0000 complete [ 614.090409] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 615.393745] 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 [ 615.394169] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 615.394562] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 615.405105] Lustre: Skipped 3 previous similar messages [ 615.414501] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 618.715976] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 625.272852] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 625.295992] Lustre: lustre-MDT0000: reset Object Index mappings [ 625.374547] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 625.381525] LustreError: Skipped 1 previous similar message [ 625.587605] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 627.686199] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 629.804611] LustreError: 42383:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 629.819040] Lustre: *** cfs_fail_loc=1601, val=1*** [ 630.752783] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 630.761481] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 630.768822] Lustre: Skipped 3 previous similar messages [ 630.786586] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 630.812170] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 630.813381] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 631.903165] Lustre: *** cfs_fail_loc=1601, val=1*** [ 631.904937] Lustre: Skipped 1 previous similar message [ 636.648852] Lustre: Failing over lustre-MDT0000 [ 636.782931] Lustre: server umount lustre-MDT0000 complete [ 641.777394] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 641.986856] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 644.039893] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 645.225313] Lustre: lustre-MDT0000: Denying connection for new client 97e7fac7-8812-48dd-8476-e06342ec4c86 (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 647.164767] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 647.169197] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 651.251621] Lustre: *** cfs_fail_loc=1505, val=0*** [ 654.769247] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 18:24:29 (1781216669) [ 656.290389] Lustre: *** cfs_fail_loc=1504, val=0*** [ 661.297784] Lustre: Failing over lustre-MDT0000 [ 661.420969] Lustre: server umount lustre-MDT0000 complete [ 662.495688] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 662.499914] LustreError: Skipped 1 previous similar message [ 664.241101] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 669.183490] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 675.112918] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 675.131551] Lustre: lustre-MDT0000: reset Object Index mappings [ 675.360183] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 675.363689] Lustre: Skipped 3 previous similar messages [ 675.398871] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 677.516030] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 679.361966] Lustre: *** cfs_fail_loc=1601, val=1*** [ 679.366578] Lustre: Skipped 1 previous similar message [ 680.446633] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 680.447415] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 690.962583] Lustre: Failing over lustre-MDT0000 [ 691.111882] Lustre: server umount lustre-MDT0000 complete [ 695.784092] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 695.792954] LustreError: 30199:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 23 previous similar messages [ 696.762571] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 696.851204] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 696.860029] LustreError: Skipped 2 previous similar messages [ 697.020561] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 698.995141] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 700.114194] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 700.123511] Lustre: Skipped 2 previous similar messages [ 702.440529] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 702.446274] Lustre: Skipped 11 previous similar messages [ 702.452482] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 702.458499] Lustre: Skipped 2 previous similar messages [ 702.495791] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 702.495797] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 706.228707] Lustre: *** cfs_fail_loc=1505, val=0*** [ 706.231807] Lustre: Skipped 84 previous similar messages [ 710.010452] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 18:25:24 (1781216724) [ 710.917703] Lustre: 25972:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 710.926696] Lustre: 25972:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1258 previous similar messages [ 710.930099] Lustre: 25972:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 710.933786] Lustre: 25972:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1258 previous similar messages [ 710.937374] Lustre: 25972:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 710.940852] Lustre: 25972:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1258 previous similar messages [ 710.944043] Lustre: 25972:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 710.947918] Lustre: 25972:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1258 previous similar messages [ 710.951897] Lustre: 25972:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 710.955599] Lustre: 25972:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1258 previous similar messages [ 710.959971] Lustre: 25972:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 710.963690] Lustre: 25972:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1258 previous similar messages [ 714.368792] Lustre: *** cfs_fail_loc=1600, val=1*** [ 714.370479] Lustre: Skipped 7 previous similar messages [ 726.515701] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 18:25:41 (1781216741) [ 731.295253] Lustre: *** cfs_fail_loc=1601, val=1*** [ 731.298092] Lustre: Skipped 7 previous similar messages [ 743.608479] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 18:25:58 (1781216758) [ 752.783758] Lustre: Failing over lustre-MDT0000 [ 752.918572] Lustre: server umount lustre-MDT0000 complete [ 753.634658] 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 [ 753.643932] Lustre: Skipped 15 previous similar messages [ 753.650167] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 753.658420] LustreError: Skipped 1 previous similar message [ 757.589057] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 757.788808] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 759.605888] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 762.875380] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 762.875380] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:854 to 0x280000401:897) [ 766.391845] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 18:26:21 (1781216781) [ 772.609706] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 780.800254] Lustre: 52602:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 791.077442] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 792.677367] Lustre: 53736:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 796.364978] Lustre: *** cfs_fail_loc=1604, val=0*** [ 796.370621] Lustre: Skipped 81 previous similar messages [ 797.775589] Lustre: *** cfs_fail_loc=1602, val=1*** [ 798.815073] Lustre: *** cfs_fail_loc=1602, val=1*** [ 799.777723] Lustre: Failing over lustre-MDT0000 [ 799.896961] Lustre: server umount lustre-MDT0000 complete [ 804.190731] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 804.426299] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 806.021099] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 809.471983] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 809.472097] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 812.923297] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 18:27:07 (1781216827) [ 814.561950] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 814.565581] Lustre: Skipped 3 previous similar messages [ 816.009376] Lustre: server umount lustre-MDT0000 complete [ 817.630706] LustreError: 26005:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781216832 with bad export cookie 13522328243008914941 [ 817.641614] LustreError: 26005:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 819.680195] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 819.682587] Lustre: Skipped 1 previous similar message [ 823.856776] Lustre: server umount lustre-MDT0001 complete [ 825.715252] Lustre: server umount lustre-OST0000 complete [ 827.399436] Lustre: server umount lustre-OST0001 complete [ 829.979656] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_hostid [ 832.879822] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 850.829876] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 855.246292] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 855.390680] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 855.413230] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 855.466708] Lustre: lustre-MDT0000: new disk, initializing [ 855.513552] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 857.239130] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 862.437992] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 862.493883] Lustre: 58816:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 862.604266] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 864.379448] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 867.155310] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 870.314948] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 870.413767] Lustre: lustre-OST0000: new disk, initializing [ 870.416319] Lustre: Skipped 1 previous similar message [ 870.418514] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 870.423766] Lustre: Skipped 2 previous similar messages [ 870.427985] Lustre: 60414:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 871.989798] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 871.993348] Lustre: Skipped 1 previous similar message [ 871.995130] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 872.023707] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 873.015707] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 878.180697] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 878.243607] Lustre: 61265:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 879.764574] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 880.831191] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 886.037376] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 887.540240] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 890.847260] Lustre: *** cfs_fail_loc=1603, val=0*** [ 891.179778] Lustre: *** cfs_fail_loc=1604, val=0*** [ 891.181955] Lustre: Skipped 19 previous similar messages [ 892.508252] Lustre: *** cfs_fail_loc=1601, val=2*** [ 892.510153] Lustre: Skipped 12 previous similar messages [ 904.026292] Lustre: Failing over lustre-MDT0000 [ 904.133296] Lustre: server umount lustre-MDT0000 complete [ 905.698064] LustreError: 58822:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 905.708057] LustreError: 58822:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 16 previous similar messages [ 908.344434] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 908.426436] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 908.433969] LustreError: Skipped 3 previous similar messages [ 908.578463] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 910.491031] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 913.891120] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 913.892329] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 913.895649] Lustre: Skipped 2 previous similar messages [ 913.898965] Lustre: Skipped 11 previous similar messages [ 913.909673] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 913.914718] Lustre: Skipped 2 previous similar messages [ 913.933462] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 913.933900] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 914.487112] Lustre: Failing over lustre-MDT0000 [ 916.596578] Lustre: server umount lustre-MDT0000 complete [ 919.007863] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 919.011581] LustreError: Skipped 2 previous similar messages [ 920.716737] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 922.586485] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 925.246206] Lustre: Failing over lustre-MDT0000 [ 925.253734] LustreError: 65234:0:(ldlm_lib.c:2985:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 925.259737] Lustre: 64703:0:(ldlm_lib.c:2388:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 925.264901] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 925.278397] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 925.284356] LustreError: 64703:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8de6c7b55e00 x1867740603275776/t0(0) o700->lustre-MDT0001-osp-MDT0000@0@lo:30/10 lens 264/248 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 925.295300] LustreError: 64703:0:(fid_request.c:213:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 925.300673] LustreError: 64703:0:(fid_request.c:316:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 925.320437] Lustre: *** cfs_fail_loc=160b, val=2*** [ 925.431847] Lustre: server umount lustre-MDT0000 complete [ 929.091631] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 930.893450] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 933.140437] Lustre: *** cfs_fail_loc=1602, val=2*** [ 934.392652] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 934.392721] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 938.995817] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 18:29:13 (1781216953) [ 944.559950] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 952.655695] Lustre: 68176:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 963.583327] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 970.245801] Lustre: 58822:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 970.250335] Lustre: 58822:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 2701 previous similar messages [ 970.253418] Lustre: 58822:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 970.257457] Lustre: 58822:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2701 previous similar messages [ 970.261272] Lustre: 58822:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 970.264180] Lustre: 58822:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2701 previous similar messages [ 970.268338] Lustre: 58822:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 970.271639] Lustre: 58822:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2701 previous similar messages [ 970.275110] Lustre: 58822:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 970.277831] Lustre: 58822:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2701 previous similar messages [ 970.280115] Lustre: 58822:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 970.282595] Lustre: 58822:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2701 previous similar messages [ 1039.940588] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 18:30:54 (1781217054) [ 1067.263647] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1067.266056] Lustre: Skipped 4 previous similar messages [ 1080.048716] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1080.053058] Lustre: Skipped 6 previous similar messages [ 1107.366490] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 18:32:02 (1781217122) [ 1130.369702] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1138.377024] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1138.379353] Lustre: Skipped 946 previous similar messages [ 1154.379315] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1154.382148] Lustre: Skipped 1711 previous similar messages [ 1195.267476] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1195.270213] Lustre: Skipped 5291 previous similar messages [ 1295.810135] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 18:35:10 (1781217310) [ 1374.689114] 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 [ 1374.689623] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1374.693623] Lustre: Skipped 20 previous similar messages [ 1374.695948] Lustre: Skipped 2 previous similar messages [ 1374.698110] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1380.177101] Lustre: server umount lustre-MDT0000 complete [ 1381.968861] LustreError: 69335:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781217397 with bad export cookie 13522328243008933575 [ 1381.970170] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1381.974696] LustreError: 69335:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1381.979280] LustreError: Skipped 2 previous similar messages [ 1382.122520] Lustre: server umount lustre-MDT0001 complete [ 1394.189863] Lustre: server umount lustre-OST0000 complete [ 1406.251303] Lustre: server umount lustre-OST0001 complete [ 1409.017757] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 1412.564230] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1427.999311] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1433.119229] LustreError: 74281:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.110@tcp: failed processing log, type 4: rc = -110 [ 1458.719174] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1458.721709] Lustre: Skipped 10 previous similar messages [ 1462.157823] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1464.049282] Lustre: 74847:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1464.060858] Lustre: *** cfs_fail_loc=160e, val=3*** [ 1467.107289] Lustre: 74847:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1472.021847] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 18:38:06 (1781217486) [ 1478.547102] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1483.150183] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1483.344239] LustreError: 74306:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1483.356702] LustreError: 74306:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 1483.430863] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3240 to 0x280000401:3265) [ 1485.042974] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1488.709186] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1490.786875] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1492.151282] Lustre: 77510:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1492.156468] Lustre: 77510:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 1498.807398] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1501.368686] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1504.228051] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3175 to 0x2c0000401:3201) [ 1505.076524] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1507.160301] Lustre: 76395:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 1507.167665] Lustre: 76395:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 37027 previous similar messages [ 1507.171295] Lustre: 76395:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 1507.173851] Lustre: 76395:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1507.177225] Lustre: 76395:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1507.182210] Lustre: 76395:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1507.187074] Lustre: 76395:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1507.193827] Lustre: 76395:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1507.199458] Lustre: 76395:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1507.204277] Lustre: 76395:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1507.207881] Lustre: 76395:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1507.211250] Lustre: 76395:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1508.627511] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1510.878025] Lustre: Failing over lustre-OST0000 [ 1510.922516] Lustre: server umount lustre-OST0000 complete [ 1515.008819] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1515.087268] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1515.090841] Lustre: Skipped 4 previous similar messages [ 1516.385801] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1516.392094] Lustre: Skipped 1 previous similar message [ 1516.400173] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1516.400190] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1516.400624] Lustre: *** cfs_fail_loc=215, val=0*** [ 1516.404883] Lustre: Skipped 7 previous similar messages [ 1516.408460] Lustre: Skipped 1 previous similar message [ 1517.514287] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1519.278442] Lustre: 80369:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1519.286443] Lustre: 80369:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1520.516698] Lustre: Failing over lustre-OST0000 [ 1520.562762] Lustre: server umount lustre-OST0000 complete [ 1524.332292] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1525.612132] Lustre: *** cfs_fail_loc=215, val=0*** [ 1525.613660] Lustre: Skipped 3 previous similar messages [ 1526.998098] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1529.824520] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1529.828546] Lustre: Skipped 7 previous similar messages [ 1535.580211] Lustre: server umount lustre-MDT0000 complete [ 1537.146058] LustreError: 77513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781217552 with bad export cookie 13522328243010490998 [ 1537.152523] LustreError: 77513:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1537.267228] Lustre: server umount lustre-MDT0001 complete [ 1549.320913] Lustre: server umount lustre-OST0000 complete [ 1560.030567] Lustre: server umount lustre-OST0001 complete [ 1563.381694] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 18:39:38 (1781217578) [ 1568.944029] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1573.715360] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1576.581403] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1580.974170] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1583.137955] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1584.797867] Lustre: 84678:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1584.804901] Lustre: 84678:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 1588.100873] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1591.246467] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1595.104375] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1598.036069] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1599.267840] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3330 to 0x280000401:3361) [ 1599.272034] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3175 to 0x2c0000401:3233) [ 1607.446847] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1625.262580] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 18:40:39 (1781217639) [ 1632.390094] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 18:40:47 (1781217647) [ 1632.925965] Lustre: *** cfs_fail_loc=160f, val=0*** [ 1637.455611] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 18:40:52 (1781217652) [ 1639.000937] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1639.003025] Lustre: Skipped 7 previous similar messages [ 1678.303912] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1678.307132] Lustre: Skipped 4 previous similar messages [ 1683.102597] Lustre: server umount lustre-MDT0000 complete [ 1684.815851] LustreError: 83554:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781217699 with bad export cookie 13522328243010499545 [ 1684.822966] LustreError: 83554:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1684.956969] Lustre: server umount lustre-MDT0001 complete [ 1696.851839] Lustre: server umount lustre-OST0000 complete [ 1708.718662] Lustre: server umount lustre-OST0001 complete [ 1715.213347] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1719.607793] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1721.472540] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1725.080910] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1726.758139] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1727.900067] Lustre: 92318:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1727.904512] Lustre: 92318:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 1730.518453] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1732.826682] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1735.777240] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 1736.216578] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1738.614404] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1741.794491] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 1744.867081] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3285 to 0x2c0000401:3329) [ 1744.869058] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3522 to 0x280000401:3553) [ 1752.815883] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1756.858465] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 18:42:51 (1781217771) [ 1758.980328] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1758.982678] Lustre: Skipped 63 previous similar messages [ 1770.467164] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1770.471511] Lustre: Skipped 7 previous similar messages [ 1771.199664] Lustre: server umount lustre-MDT0000 complete [ 1773.206404] LustreError: 91195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781217788 with bad export cookie 13522328243010527951 [ 1773.210787] LustreError: 91195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1773.362519] Lustre: server umount lustre-MDT0001 complete [ 1785.818115] Lustre: server umount lustre-OST0000 complete [ 1797.668586] Lustre: server umount lustre-OST0001 complete [ 1804.470388] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1808.915091] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1810.765977] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1814.397977] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1816.366434] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1820.807356] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1823.460515] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1824.036851] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 1827.484679] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1830.209493] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1832.934877] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 1834.983484] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3650 to 0x280000401:3681) [ 1834.984221] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3285 to 0x2c0000401:3361) [ 1839.526885] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1844.889722] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 18:44:19 (1781217859) [ 1846.615450] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1846.617498] Lustre: Skipped 63 previous similar messages [ 1846.718443] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1851.479890] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 18:44:26 (1781217866) [ 1852.531743] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1852.573547] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1852.579341] Lustre: Skipped 3 previous similar messages [ 1857.081540] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 18:44:31 (1781217871) [ 1857.708378] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 1858.441656] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 18:44:33 (1781217873) [ 1862.312810] Lustre: *** cfs_fail_loc=1709, val=0*** [ 1862.315688] LustreError: 97056:0:(mdt_reint.c:2636:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f3 failed: rc = -5 [ 1911.776797] 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 [ 1911.777241] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1911.781420] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1911.781432] Lustre: Skipped 1 previous similar message [ 1911.791938] Lustre: Skipped 19 previous similar messages [ 1911.797713] LustreError: Skipped 6 previous similar messages [ 1914.897611] Lustre: server umount lustre-MDT0000 complete [ 1918.854581] LustreError: 100340:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781217934 with bad export cookie 13522328243010542679 [ 1918.854805] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1918.854809] LustreError: Skipped 3 previous similar messages [ 1918.868376] LustreError: 100340:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1918.990781] Lustre: server umount lustre-MDT0001 complete [ 1933.204713] Lustre: server umount lustre-OST0000 complete [ 1946.026231] Lustre: server umount lustre-OST0001 complete [ 1952.521233] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing unload_modules_local [ 1953.802270] Key type lgssc unregistered [ 1953.944133] LNet: 103796:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 1953.949233] LNetError: 103796:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 1953.960072] LNet: Removed LNI 192.168.206.110@tcp [ 1954.367182] Key type .llcrypt unregistered [ 1954.369131] Key type ._llcrypt unregistered [ 1965.610785] Key type ._llcrypt registered [ 1965.612184] Key type .llcrypt registered [ 1965.661275] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_hostid [ 1971.890431] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1972.200147] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 1972.213209] alg: No test for adler32 (adler32-zlib) [ 1973.093509] Lustre: Lustre: Build Version: 2.17.53_75_g2ada427 [ 1973.189557] LNet: Added LNI 192.168.206.110@tcp [8/256/0/180] [ 1974.800091] Key type lgssc registered [ 1975.268816] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1994.153312] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 1999.801237] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1999.821436] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2000.942487] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2000.961370] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2001.002777] Lustre: lustre-MDT0000: new disk, initializing [ 2001.036428] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2001.044941] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2002.652268] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2008.393207] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2008.428290] Lustre: 108170:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2008.441926] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2008.444406] Lustre: Skipped 1 previous similar message [ 2008.480244] Lustre: lustre-MDT0001: new disk, initializing [ 2008.500827] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2008.509680] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2008.513925] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2010.037906] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2012.754971] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2017.514761] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2017.654156] Lustre: lustre-OST0000: new disk, initializing [ 2017.657067] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2017.661284] Lustre: 110078:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2017.688742] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2020.188662] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2025.469427] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2025.476204] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2025.525295] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2027.051901] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2027.099579] Lustre: lustre-OST0001: new disk, initializing [ 2027.102263] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2027.105519] Lustre: 111083:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2027.131551] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2029.765085] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2033.144924] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2033.150889] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2033.166680] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2036.112849] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2042.284697] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2044.515828] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 18:47:39 (1781218059) === [ 2047.376744] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 18:47:42 (1781218062) [ 2047.466251] Lustre: 109440:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 2047.473421] Lustre: 109440:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2047.477259] Lustre: 109440:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2047.480944] Lustre: 109440:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 2047.485415] Lustre: 109440:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2047.489572] Lustre: 109440:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2047.972179] Lustre: 108179:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 2047.976720] Lustre: 108179:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 90 previous similar messages [ 2047.981031] Lustre: 108179:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2047.985625] Lustre: 108179:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 90 previous similar messages [ 2047.990396] Lustre: 108179:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2047.996903] Lustre: 108179:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 90 previous similar messages [ 2048.000518] Lustre: 108179:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 2048.004251] Lustre: 108179:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 90 previous similar messages [ 2048.007746] Lustre: 108179:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 2048.011031] Lustre: 108179:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 90 previous similar messages [ 2048.014676] Lustre: 108179:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2048.018311] Lustre: 108179:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 90 previous similar messages [ 2049.084439] Lustre: *** cfs_fail_loc=1613, val=0*** [ 2053.767753] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 18:47:48 (1781218068) [ 2054.401822] Lustre: 108177:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 2054.406267] Lustre: 108177:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 218 previous similar messages [ 2054.410769] Lustre: 108177:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2054.414520] Lustre: 108177:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 2054.418123] Lustre: 108177:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2054.421891] Lustre: 108177:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 2054.425709] Lustre: 108177:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2054.429149] Lustre: 108177:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 2054.432595] Lustre: 108177:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2054.436564] Lustre: 108177:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 2054.440203] Lustre: 108177:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2054.444282] Lustre: 108177:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 2054.970557] Lustre: *** cfs_fail_loc=1614, val=0*** [ 2057.095712] Lustre: 110068:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 2057.101108] Lustre: 110068:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 11 previous similar messages [ 2057.105525] Lustre: 110068:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2057.109815] Lustre: 110068:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2057.114131] Lustre: 110068:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 2057.118576] Lustre: 110068:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2057.124021] Lustre: 110068:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 2057.127628] Lustre: 110068:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2057.130693] Lustre: 110068:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2057.133372] Lustre: 110068:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2057.136477] Lustre: 110068:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2057.139850] Lustre: 110068:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2060.317418] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 18:47:54 (1781218074) [ 2061.166963] Lustre: 110066:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 2061.173867] Lustre: 113145:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2061.176100] Lustre: 110066:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 20 previous similar messages [ 2061.179810] Lustre: 113145:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 19 previous similar messages [ 2061.179832] Lustre: 113145:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 2061.179837] Lustre: 113145:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 19 previous similar messages [ 2061.179843] Lustre: 113145:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 2061.179847] Lustre: 113145:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 19 previous similar messages [ 2061.179853] Lustre: 113145:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2061.179857] Lustre: 113145:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 19 previous similar messages [ 2061.179863] Lustre: 113145:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2061.229298] Lustre: 113145:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2061.902040] Lustre: *** cfs_fail_loc=1615, val=0*** [ 2061.906695] Lustre: Skipped 1 previous similar message [ 2065.871045] LustreError: 113385:0:(lfsck_layout.c:2103:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0x6d:0x0] and [0x280000401:0x6d:0x0]d: rc = 0 [ 2071.463365] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 2072.193915] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 18:48:06 (1781218086) [ 2072.365489] Lustre: 108178:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2072.369744] Lustre: 108178:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 2 previous similar messages [ 2072.372975] Lustre: 108178:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2072.376899] Lustre: 108178:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2072.381078] Lustre: 108178:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2072.385107] Lustre: 108178:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2072.389831] Lustre: 108178:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2072.393816] Lustre: 108178:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2072.397928] Lustre: 108178:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 2072.401036] Lustre: 108178:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2072.404584] Lustre: 108178:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2072.408703] Lustre: 108178:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 2073.282945] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2073.319591] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2074.343857] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2074.347263] Lustre: Skipped 5 previous similar messages [ 2083.586392] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 18:48:18 (1781218098) [ 2084.547525] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2084.549346] Lustre: Skipped 5 previous similar messages [ 2120.161387] 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 [ 2120.162283] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2120.166569] Lustre: Skipped 3 previous similar messages [ 2120.169582] Lustre: Skipped 2 previous similar messages [ 2122.617664] Lustre: server umount lustre-MDT0000 complete [ 2124.239802] LustreError: 109104:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781218139 with bad export cookie 13112794200322837644 [ 2124.241245] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2124.246102] LustreError: 109104:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 2124.397687] Lustre: server umount lustre-MDT0001 complete [ 2136.399772] Lustre: server umount lustre-OST0000 complete [ 2148.645869] Lustre: server umount lustre-OST0001 complete [ 2156.435385] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 2161.392032] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2161.656421] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2163.587087] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2166.752099] LustreError: 116753:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2166.763666] LustreError: 116753:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 2167.901063] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2169.956402] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2171.476672] Lustre: 117860:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2174.896904] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2175.056782] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2175.062539] Lustre: Skipped 1 previous similar message [ 2177.928460] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2178.146062] LustreError: 118212:0:(ldlm_lib.c:1179: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. [ 2178.151885] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 2182.473219] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2185.240455] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2186.661987] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 2186.663191] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 2186.698773] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 2194.720716] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2196.340542] Lustre: 119691:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2202.817267] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 18:50:17 (1781218217) [ 2203.006932] Lustre: 116750:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 2203.013078] Lustre: 116750:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 46 previous similar messages [ 2203.019154] Lustre: 116750:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2203.023924] Lustre: 116750:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 2203.027326] Lustre: 116750:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2203.031378] Lustre: 116750:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 2203.035682] Lustre: 116750:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 2203.040706] Lustre: 116750:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 2203.045322] Lustre: 116750:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2203.049230] Lustre: 116750:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 2203.052312] Lustre: 116750:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2203.056990] Lustre: 116750:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 2204.128817] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2204.132225] Lustre: Skipped 3 previous similar messages [ 2237.922360] 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 [ 2237.922696] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2237.930331] Lustre: Skipped 2 previous similar messages [ 2237.937364] Lustre: Skipped 2 previous similar messages [ 2242.068814] Lustre: server umount lustre-MDT0000 complete [ 2243.040336] LustreError: 116754:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2243.052042] LustreError: 116754:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 2244.207566] LustreError: 116733:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781218259 with bad export cookie 13112794200322852883 [ 2244.207676] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2244.215456] LustreError: 116733:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2244.395890] Lustre: server umount lustre-MDT0001 complete [ 2256.394027] Lustre: server umount lustre-OST0000 complete [ 2268.475633] Lustre: server umount lustre-OST0001 complete [ 2276.525775] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 2281.538081] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2281.782921] LustreError: 122237:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2281.827159] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2281.831950] Lustre: Skipped 1 previous similar message [ 2283.558653] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2287.071511] LustreError: 122238:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2287.409334] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2289.516267] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2290.871147] Lustre: 123342:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2294.156864] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2296.943339] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2297.377055] LustreError: 123695:0:(ldlm_lib.c:1179: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. [ 2297.381744] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 2300.990688] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2303.891184] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2306.213091] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 2306.217834] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 2306.245583] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 2313.087459] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2314.947374] Lustre: 125178:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2317.704604] Lustre: 125429:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 2317.710978] Lustre: 125429:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 21 previous similar messages [ 2317.718452] Lustre: 125429:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2317.723389] Lustre: 125429:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2317.726646] Lustre: 125429:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 2317.732336] Lustre: 125429:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2317.737413] Lustre: *** cfs_fail_loc=1602, val=10*** [ 2317.737542] Lustre: 125429:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 2317.743765] Lustre: 125429:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2317.747337] Lustre: 125429:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 2317.751241] Lustre: 125429:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2317.755029] Lustre: 125429:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2317.758945] Lustre: 125429:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2336.182235] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 18:52:30 (1781218350) [ 2337.780406] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2337.782381] Lustre: Skipped 3 previous similar messages [ 2342.072111] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2350.650582] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 18:52:45 (1781218365) [ 2351.616524] Lustre: *** cfs_fail_loc=162e, val=0*** [ 2358.050525] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 18:52:52 (1781218372) [ 2360.550280] Lustre: *** cfs_fail_loc=162f, val=0*** [ 2360.552590] Lustre: Skipped 9 previous similar messages [ 2361.432795] LustreError: 128265:0:(lfsck_layout.c:2103:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x2c0000401:0x44:0x0] and [0x2c0000401:0x44:0x0]d: rc = 0 [ 2368.372979] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 18:53:03 (1781218383) [ 2374.983845] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 18:53:09 (1781218389) [ 2376.454979] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2376.472664] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2376.474848] Lustre: Skipped 3 previous similar messages [ 2379.464837] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.10@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 2380.553130] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.10@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 2383.858356] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 18:53:18 (1781218398) [ 2383.985306] Lustre: 124945:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 2383.989313] Lustre: 124945:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 104 previous similar messages [ 2383.991936] Lustre: 124945:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2383.994531] Lustre: 124945:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 2383.997267] Lustre: 124945:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2384.000666] Lustre: 124945:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 2384.004448] Lustre: 124945:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 2384.008971] Lustre: 124945:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 2384.012976] Lustre: 124945:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2384.017057] Lustre: 124945:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 2384.021377] Lustre: 124945:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2384.024470] Lustre: 124945:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 2423.738638] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 18:53:58 (1781218438) [ 2426.703932] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 18:54:01 (1781218441) [ 2432.923209] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 18:54:07 (1781218447) [ 2434.235203] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2434.240515] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2434.244255] Lustre: Skipped 1 previous similar message [ 2440.020079] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 18:54:14 (1781218454) [ 2440.847395] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2440.851456] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2446.022286] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 18:54:20 (1781218460) [ 2446.852867] Lustre: *** cfs_fail_loc=1620, val=0*** [ 2453.510333] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 2454.309615] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 18:54:29 (1781218469) [ 2457.094600] Lustre: *** cfs_fail_loc=1621, val=127*** [ 2457.098051] Lustre: Skipped 1 previous similar message [ 2458.302898] Lustre: *** cfs_fail_loc=1602, val=10*** [ 2472.952347] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 18:54:47 (1781218487) [ 2473.934277] Lustre: Failing over lustre-MDT0000 [ 2474.141525] Lustre: server umount lustre-MDT0000 complete [ 2475.488494] 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 [ 2475.488856] LustreError: 122237:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2475.495268] Lustre: Skipped 4 previous similar messages [ 2475.506929] LustreError: 122237:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 2478.276744] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2478.343165] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2478.442531] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2478.446325] Lustre: Skipped 3 previous similar messages [ 2478.462309] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2480.037414] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2481.609705] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2483.686715] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2483.699217] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 2483.718908] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 2483.718911] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 2483.719982] LustreError: 122234:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 2488.024294] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 18:55:02 (1781218502) [ 2488.864271] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2488.919331] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2488.920893] Lustre: Skipped 1 previous similar message [ 2493.514613] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 18:55:08 (1781218508) [ 2494.173558] Lustre: *** cfs_fail_loc=1623, val=0*** [ 2498.528271] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 18:55:13 (1781218513) [ 2499.163372] Lustre: *** cfs_fail_loc=1624, val=0*** [ 2504.098535] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 18:55:18 (1781218518) [ 2510.124361] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 18:55:24 (1781218524) [ 2515.893071] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 18:55:30 (1781218530) [ 2515.995970] Lustre: 123416:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2516.000255] Lustre: 123416:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 487 previous similar messages [ 2516.003970] Lustre: 123416:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2516.006571] Lustre: 123416:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 487 previous similar messages [ 2516.010022] Lustre: 123416:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2516.012943] Lustre: 123416:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 487 previous similar messages [ 2516.015668] Lustre: 123416:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2516.020130] Lustre: 123416:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 487 previous similar messages [ 2516.023635] Lustre: 123416:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 2516.026669] Lustre: 123416:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 487 previous similar messages [ 2516.030831] Lustre: 123416:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2516.035403] Lustre: 123416:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 487 previous similar messages [ 2516.595069] Lustre: *** cfs_fail_loc=1624, val=0*** [ 2516.596843] Lustre: Skipped 3 previous similar messages [ 2521.739408] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 18:55:36 (1781218536) [ 2525.029747] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2525.032333] Lustre: Skipped 2 previous similar messages [ 2532.100721] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 18:55:46 (1781218546) [ 2538.305405] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 18:55:53 (1781218553) [ 2553.604751] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 18:56:08 (1781218568) [ 2554.377383] Lustre: *** cfs_fail_loc=1626, val=0*** [ 2554.379603] Lustre: Skipped 3 previous similar messages [ 2554.933752] LustreError: 122233:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 2558.371628] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 18:56:12 (1781218572) [ 2585.437063] Lustre: Failing over lustre-MDT0000 [ 2585.629687] Lustre: server umount lustre-MDT0000 complete [ 2586.080698] 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 [ 2586.083151] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2586.091490] LustreError: 122232:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2586.098260] LustreError: 122232:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 2591.046020] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2591.127593] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2591.202395] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 2591.206886] Lustre: Skipped 3 previous similar messages [ 2591.261762] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2591.291740] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2593.062829] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2596.321255] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2596.324655] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2596.329821] Lustre: Skipped 3 previous similar messages [ 2596.339821] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2596.367487] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 2596.367805] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 2601.092498] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 18:56:55 (1781218615) [ 2607.157785] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 18:57:01 (1781218621) [ 2614.595488] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 18:57:09 (1781218629) [ 2615.343175] Lustre: *** cfs_fail_loc=1629, val=0*** [ 2615.345382] Lustre: Skipped 7 previous similar messages [ 2621.594674] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 18:57:16 (1781218636) [ 2624.561803] Lustre: Failing over lustre-MDT0000 [ 2624.725513] Lustre: server umount lustre-MDT0000 complete [ 2627.043448] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2627.043460] 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 [ 2627.043476] Lustre: Skipped 3 previous similar messages [ 2628.691031] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2628.762302] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2628.895956] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2630.897309] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2631.980398] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2631.986844] Lustre: lustre-MDT0000: Denying connection for new client a5ebfc9c-f338-4e29-93f6-6a33151ad7cb (at 192.168.206.10@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 2634.214307] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2634.217661] Lustre: Skipped 3 previous similar messages [ 2634.229051] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 2634.252345] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 2634.252651] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 2640.819432] Lustre: Failing over lustre-MDT0000 [ 2641.028761] Lustre: server umount lustre-MDT0000 complete [ 2644.448876] 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 [ 2644.451541] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2644.454118] Lustre: Skipped 2 previous similar messages [ 2645.226970] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2645.284375] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2645.425841] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2647.315875] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2647.498748] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2650.597284] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2650.603416] Lustre: Skipped 3 previous similar messages [ 2650.623147] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 2650.648508] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 2650.648508] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:257) [ 2654.077810] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 18:57:48 (1781218668) [ 2655.312013] hrtimer: interrupt took 3013524 ns [ 2660.225879] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 18:57:54 (1781218674) [ 2665.788991] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 18:58:00 (1781218680) [ 2700.036531] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 18:58:34 (1781218714) [ 2700.676808] Lustre: *** cfs_fail_loc=162c, val=0*** [ 2700.679439] Lustre: Skipped 13 previous similar messages [ 2706.555574] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 18:58:41 (1781218721) [ 2710.456555] LustreError: 146730:0:(lfsck_layout.c:4532:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2711.648367] Lustre: Failing over lustre-OST0000 [ 2711.701550] Lustre: server umount lustre-OST0000 complete [ 2712.036040] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2712.038730] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2712.042175] LustreError: 124082:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2712.051810] Lustre: Skipped 4 previous similar messages [ 2712.061440] LustreError: 124082:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 2712.960111] LustreError: 146730:0:(lfsck_layout.c:4532:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 2720.437393] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2720.565500] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2720.569341] Lustre: Skipped 2 previous similar messages [ 2720.576695] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2722.531411] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2722.544080] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2722.544029] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2722.552297] Lustre: Skipped 3 previous similar messages [ 2723.308702] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2727.186767] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 18:59:01 (1781218741) [ 2733.500636] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 2741.575288] Lustre: 149496:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2752.163992] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2758.103401] LustreError: 150738:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2759.378404] Lustre: Failing over lustre-MDT0001 [ 2761.127154] LustreError: 150737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 2761.132541] LustreError: 150737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2761.133315] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 2761.136975] LustreError: 150737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 2761.145316] LustreError: Skipped 1 previous similar message [ 2761.147551] 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 [ 2761.154652] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2761.255572] Lustre: server umount lustre-MDT0001 complete [ 2762.488059] LustreError: 150737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 2769.640279] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2769.809036] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2771.451186] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2775.011272] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2775.012561] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2775.017186] Lustre: Skipped 1 previous similar message [ 2775.028173] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2775.050563] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 2775.050926] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 2775.330758] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 18:59:50 (1781218790) [ 2781.717691] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 2790.576278] Lustre: 153417:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2790.581912] Lustre: 153417:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 2802.697936] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2805.850494] Lustre: 122232:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 2805.855418] Lustre: 122232:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1247 previous similar messages [ 2805.859670] Lustre: 122232:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2805.863903] Lustre: 122232:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1247 previous similar messages [ 2805.868603] Lustre: 122232:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2805.872391] Lustre: 122232:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1247 previous similar messages [ 2805.876154] Lustre: 122232:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2805.880361] Lustre: 122232:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1247 previous similar messages [ 2805.884150] Lustre: 122232:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2805.887623] Lustre: 122232:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1247 previous similar messages [ 2805.891456] Lustre: 122232:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2805.895303] Lustre: 122232:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1247 previous similar messages [ 2814.995171] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 19:00:29 (1781218829) [ 2815.708960] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 2816.485815] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 19:00:31 (1781218831) [ 2819.605582] Lustre: *** cfs_fail_loc=1631, val=0*** [ 2826.209710] 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 [ 2826.210336] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2826.210509] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2826.214450] Lustre: Skipped 4 previous similar messages [ 2831.726279] Lustre: server umount lustre-MDT0000 complete [ 2833.405454] LustreError: 123721:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781218848 with bad export cookie 13112794200322925522 [ 2833.405663] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2833.416304] LustreError: 123721:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2833.566902] Lustre: server umount lustre-MDT0001 complete [ 2845.719309] Lustre: server umount lustre-OST0000 complete [ 2857.909034] Lustre: server umount lustre-OST0001 complete [ 2865.390896] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 2869.447495] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2869.632970] LustreError: 157302:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2869.641077] LustreError: 157302:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 2871.377084] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2875.313863] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2877.206369] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2878.525290] Lustre: 158408:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2878.529873] Lustre: 158408:0:(mgs_llog.c:1437:mgs_modify_param()) Skipped 1 previous similar message [ 2881.582931] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2884.230642] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2885.860420] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 2888.056270] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2890.602629] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2893.284604] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 2894.309383] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 2894.334099] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 2899.787497] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2905.524703] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 19:02:00 (1781218920) [ 2906.212378] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 2907.031877] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 19:02:01 (1781218921) [ 2907.761398] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 2908.520701] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 19:02:03 (1781218923) [ 2909.219486] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 2909.959853] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 19:02:04 (1781218924) [ 2914.505651] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 19:02:09 (1781218929) [ 2920.848139] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 19:02:15 (1781218935) [ 2927.025088] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 19:02:21 (1781218941) [ 2933.696057] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 19:02:28 (1781218948) [ 2942.446916] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 19:02:37 (1781218957) [ 2974.638723] Lustre: *** cfs_fail_loc=1632, val=0*** [ 2981.361718] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 19:03:15 (1781218995) [ 2982.632868] Lustre: Failing over lustre-MDT0001 [ 2982.743141] Lustre: server umount lustre-MDT0001 complete [ 2985.964039] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2986.082915] 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 [ 2986.088096] Lustre: Skipped 2 previous similar messages [ 2986.113798] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2986.117449] Lustre: Skipped 5 previous similar messages [ 2986.126605] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2986.126710] Lustre: lustre-MDT0001: Aborting client recovery [ 2986.133322] LustreError: 164028:0:(ldlm_lib.c:2985:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 2986.137694] Lustre: 164052:0:(ldlm_lib.c:2388:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2986.140984] Lustre: 164052:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 71bc4a45-ba7e-4583-96dc-22caa8c8c2e0@ [ 2986.145940] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 2986.149701] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 2986.154899] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 2986.176203] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:161) [ 2986.176399] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:131 to 0x2c0000400:161) [ 2987.777311] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2989.549373] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 2991.308241] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 2991.585776] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 2991.594498] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2991.602447] Lustre: Skipped 3 previous similar messages [ 2992.490215] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 1 sec [ 2995.432561] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 19:03:30 (1781219010) [ 2999.300370] Lustre: *** cfs_fail_loc=1600, val=3*** [ 3001.116821] Lustre: Failing over lustre-MDT0000 [ 3001.255165] Lustre: server umount lustre-MDT0000 complete [ 3001.824519] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3005.708434] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3005.773951] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3007.788493] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3010.505192] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3011.053204] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3011.079134] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 3011.079212] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 3011.878342] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 19:03:46 (1781219026) [ 3026.563909] Lustre: Failing over lustre-OST0000 [ 3026.642585] Lustre: server umount lustre-OST0000 complete [ 3029.527180] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 3034.611596] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3034.710750] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3034.713962] Lustre: Skipped 3 previous similar messages [ 3036.390746] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3036.394171] Lustre: Skipped 5 previous similar messages [ 3037.055711] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3039.573129] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 3039.673934] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 3041.484332] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 3041.586896] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 3043.203409] Lustre: DEBUG MARKER: oleg610-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff89b508f27800.ost_server_uuid 50 [ 3043.876543] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff89b508f27800.ost_server_uuid in FULL state after 0 sec [ 3063.894125] Lustre: server umount lustre-MDT0000 complete [ 3067.688059] LustreError: 160956:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781219082 with bad export cookie 13112794200323008472 [ 3067.694417] LustreError: 160956:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3067.794709] Lustre: server umount lustre-MDT0001 complete [ 3081.500530] Lustre: server umount lustre-OST0000 complete [ 3094.983971] Lustre: server umount lustre-OST0001 complete [ 3102.806781] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing unload_modules_local [ 3104.090324] Key type lgssc unregistered [ 3104.253388] LNet: 172937:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3104.257641] LNetError: 172937:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3104.266760] LNet: Removed LNI 192.168.206.110@tcp [ 3104.632134] Key type .llcrypt unregistered [ 3104.633685] Key type ._llcrypt unregistered [ 3114.769084] Key type ._llcrypt registered [ 3114.770589] Key type .llcrypt registered [ 3114.819046] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_hostid [ 3122.923317] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 3123.338533] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3123.346520] alg: No test for adler32 (adler32-zlib) [ 3124.238703] Lustre: Lustre: Build Version: 2.17.53_75_g2ada427 [ 3124.342821] LNet: Added LNI 192.168.206.110@tcp [8/256/0/180] [ 3125.935180] Key type lgssc registered [ 3126.499617] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3148.721565] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing load_modules_local [ 3154.684984] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3154.699715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3155.829708] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3155.845025] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3155.887455] Lustre: lustre-MDT0000: new disk, initializing [ 3155.927744] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3155.937344] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3157.911381] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3164.129931] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3164.174570] Lustre: 177312:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3164.192353] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3164.195290] Lustre: Skipped 1 previous similar message [ 3164.233462] Lustre: lustre-MDT0001: new disk, initializing [ 3164.263338] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3164.279733] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3164.285735] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3165.873115] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3168.422676] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3172.266670] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3172.367678] Lustre: lustre-OST0000: new disk, initializing [ 3172.369278] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3172.373608] Lustre: 179215:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3172.406557] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3174.734254] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3176.499185] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3176.503717] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3176.543188] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3181.069038] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3181.149838] Lustre: lustre-OST0001: new disk, initializing [ 3181.153346] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3181.156525] Lustre: 180221:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3181.191141] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3183.668278] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3183.672215] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3183.700791] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3183.805577] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3190.033850] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3195.140282] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3197.616765] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 19:06:52 (1781219212) === [ 3198.322199] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 3057 sec ========= 19:06:53 (1781219213) [ 3199.057725] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 19:06:53 (1781219213) === [ 3200.496368] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 19:06:55 (1781219215) === [ 3204.063833] 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 [ 3204.064198] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3204.071135] Lustre: Skipped 3 previous similar messages [ 3204.075157] Lustre: Skipped 2 previous similar messages [ 3207.902184] Lustre: server umount lustre-MDT0000 complete [ 3211.707601] LustreError: 180220:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1781219226 with bad export cookie 12417445550216462504 [ 3211.708856] LustreError: MGC192.168.206.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3211.712974] LustreError: 180220:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3211.839352] Lustre: server umount lustre-MDT0001 complete [ 3225.812726] Lustre: server umount lustre-OST0000 complete [ 3239.026537] Lustre: server umount lustre-OST0001 complete [ 3247.131449] Lustre: DEBUG MARKER: oleg610-server.virtnet: executing unload_modules_local [ 3248.553988] Key type lgssc unregistered [ 3248.718589] LNet: 183658:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3248.723677] LNetError: 183658:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3248.735533] LNet: Removed LNI 192.168.206.110@tcp [ 3249.176834] Key type .llcrypt unregistered [ 3249.178441] Key type ._llcrypt unregistered