[ 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 447969721 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.003242] x2apic enabled [ 0.004008] Switched APIC routing to physical x2apic. [ 0.005016] kvm-guest: setup PV IPIs [ 0.008643] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009025] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010013] pid_max: default: 32768 minimum: 301 [ 0.011146] LSM: Security Framework initializing [ 0.012055] Yama: becoming mindful. [ 0.013040] SELinux: Initializing. [ 0.014071] *** VALIDATE selinux *** [ 0.023028] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028285] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029153] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031062] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.033111] *** VALIDATE tmpfs *** [ 0.034479] *** VALIDATE proc *** [ 0.035246] *** VALIDATE cgroup *** [ 0.036009] *** VALIDATE cgroup2 *** [ 0.038130] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.039173] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.040009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.042030] Spectre V2 : User space: Vulnerable [ 0.043009] Speculative Store Bypass: Vulnerable [ 0.046462] debug: unmapping init [mem 0xffffffffba859000-0xffffffffba860fff] [ 0.049183] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.050696] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.051026] ... version: 2 [ 0.052012] ... bit width: 48 [ 0.053011] ... generic registers: 4 [ 0.054012] ... value mask: 0000ffffffffffff [ 0.055014] ... max period: 00007fffffffffff [ 0.056014] ... fixed-purpose events: 3 [ 0.057011] ... event mask: 000000070000000f [ 0.058332] rcu: Hierarchical SRCU implementation. [ 0.060472] smp: Bringing up secondary CPUs ... [ 0.061594] x86: Booting SMP configuration: [ 0.062027] .... node #0, CPUs: #1 #2 #3 [ 0.071086] smp: Brought up 1 node, 4 CPUs [ 0.073013] smpboot: Max logical packages: 1 [ 0.074013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.155058] node 0 deferred pages initialised in 79ms [ 0.158009] devtmpfs: initialized [ 0.159247] x86/mm: Memory block size: 128MB [ 0.161901] gcov: version magic: 0x41383552 [ 0.165302] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.166079] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.167268] pinctrl core: initialized pinctrl subsystem [ 0.168218] [ 0.168839] ************************************************************* [ 0.169014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.170011] ** ** [ 0.171014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.172013] ** ** [ 0.173012] ** This means that this kernel is built to expose internal ** [ 0.174013] ** IOMMU data structures, which may compromise security on ** [ 0.175013] ** your system. ** [ 0.176017] ** ** [ 0.177025] ** If you see this message and you are not debugging the ** [ 0.178013] ** kernel, report this immediately to your vendor! ** [ 0.179013] ** ** [ 0.180013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.181015] ************************************************************* [ 0.183578] NET: Registered protocol family 16 [ 0.184439] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.185058] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.186060] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.187481] cpuidle: using governor menu [ 0.189550] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.191368] PCI: Using configuration type 1 for base access [ 0.192130] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.201098] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.202031] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.205028] cryptd: max_cpu_qlen set to 1000 [ 0.207219] ACPI: Added _OSI(Module Device) [ 0.208012] ACPI: Added _OSI(Processor Device) [ 0.210012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.211009] ACPI: Added _OSI(Processor Aggregator Device) [ 0.215007] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.221377] ACPI: Interpreter enabled [ 0.222049] ACPI: PM: (supports S0 S3 S4 S5) [ 0.223010] ACPI: Using IOAPIC for interrupt routing [ 0.224168] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.227342] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.241024] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.243045] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.245021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.248111] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.253447] acpiphp: Slot [2] registered [ 0.255163] acpiphp: Slot [5] registered [ 0.256094] acpiphp: Slot [6] registered [ 0.258116] acpiphp: Slot [7] registered [ 0.260303] acpiphp: Slot [8] registered [ 0.262209] acpiphp: Slot [9] registered [ 0.264202] acpiphp: Slot [10] registered [ 0.266197] acpiphp: Slot [3] registered [ 0.269153] acpiphp: Slot [4] registered [ 0.271146] acpiphp: Slot [11] registered [ 0.273240] acpiphp: Slot [12] registered [ 0.275169] acpiphp: Slot [13] registered [ 0.277192] acpiphp: Slot [14] registered [ 0.280215] acpiphp: Slot [15] registered [ 0.282225] acpiphp: Slot [16] registered [ 0.284089] acpiphp: Slot [17] registered [ 0.286131] acpiphp: Slot [18] registered [ 0.288094] acpiphp: Slot [19] registered [ 0.289115] acpiphp: Slot [20] registered [ 0.291157] acpiphp: Slot [21] registered [ 0.292092] acpiphp: Slot [22] registered [ 0.293100] acpiphp: Slot [23] registered [ 0.295133] acpiphp: Slot [24] registered [ 0.296088] acpiphp: Slot [25] registered [ 0.298124] acpiphp: Slot [26] registered [ 0.299087] acpiphp: Slot [27] registered [ 0.301118] acpiphp: Slot [28] registered [ 0.303129] acpiphp: Slot [29] registered [ 0.305146] acpiphp: Slot [30] registered [ 0.306121] acpiphp: Slot [31] registered [ 0.308058] PCI host bridge to bus 0000:00 [ 0.309020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.311027] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.314022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.316027] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.319064] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.323050] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.326381] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.328852] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.332248] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.342884] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.348074] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.351016] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.353018] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.355020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.358677] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.361901] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.365077] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.368903] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.374024] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.389013] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.394770] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.401391] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.411014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.416017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.432019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.445247] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.451015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.456018] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.468018] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.477821] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.486014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.494014] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.520017] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.529245] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.534017] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.539012] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.549027] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.556846] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.565015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.572016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.589016] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.600755] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.618015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.625013] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.651026] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.663082] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.666386] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.670471] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.674549] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.678243] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.683130] iommu: Default domain type: Passthrough [ 0.685467] SCSI subsystem initialized [ 0.686077] ACPI: bus type USB registered [ 0.688133] usbcore: registered new interface driver usbfs [ 0.691152] usbcore: registered new interface driver hub [ 0.694105] usbcore: registered new device driver usb [ 0.697181] pps_core: LinuxPPS API ver. 1 registered [ 0.700014] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.705070] PTP clock support registered [ 0.707180] EDAC MC: Ver: 3.0.0 [ 0.710137] PCI: Using ACPI for IRQ routing [ 0.713194] NetLabel: Initializing [ 0.714012] NetLabel: domain hash size = 128 [ 0.715009] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.717080] NetLabel: unlabeled traffic allowed by default [ 0.718108] vgaarb: loaded [ 0.720248] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.721011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.731079] clocksource: Switched to clocksource kvm-clock [ 0.841738] VFS: Disk quotas dquot_6.6.0 [ 0.843477] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.846156] *** VALIDATE ramfs *** [ 0.847564] *** VALIDATE hugetlbfs *** [ 0.849211] pnp: PnP ACPI init [ 0.851668] pnp: PnP ACPI: found 6 devices [ 0.868648] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.872081] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.874362] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.876700] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.879197] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.881713] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.884637] NET: Registered protocol family 2 [ 0.887055] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.891464] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.895373] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.900817] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.904517] TCP: Hash tables configured (established 65536 bind 65536) [ 0.908089] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.911159] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.913923] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.916868] NET: Registered protocol family 1 [ 0.919390] RPC: Registered named UNIX socket transport module. [ 0.921992] RPC: Registered udp transport module. [ 0.923836] RPC: Registered tcp transport module. [ 0.925576] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.928616] NET: Registered protocol family 44 [ 0.930827] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.933733] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.935735] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.938155] PCI: CLS 0 bytes, default 64 [ 0.939824] Unpacking initramfs... [ 2.195973] debug: unmapping init [mem 0xffff8c24fcc54000-0xffff8c24fffbffff] [ 2.198848] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.200393] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.202662] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.700558] Initialise system trusted keyrings [ 2.702996] Key type blacklist registered [ 2.705044] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.713423] zbud: loaded [ 2.715799] *** VALIDATE nfs *** [ 2.716610] *** VALIDATE nfs4 *** [ 2.717902] pstore: using deflate compression [ 2.720908] Platform Keyring initialized [ 2.811888] NET: Registered protocol family 38 [ 2.813810] Key type asymmetric registered [ 2.815323] Asymmetric key parser 'x509' registered [ 2.817093] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.820137] io scheduler mq-deadline registered [ 2.821546] io scheduler kyber registered [ 2.822498] io scheduler bfq registered [ 2.823990] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.826427] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.829222] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.831763] ACPI: Power Button [PWRF] [ 2.835121] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.839668] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.847405] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.852400] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.866809] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.891145] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.915766] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.920626] Non-volatile memory driver v1.3 [ 2.922077] Linux agpgart interface v0.103 [ 2.956594] virtio_blk virtio1: [vda] 146608 512-byte logical blocks (75.1 MB/71.6 MiB) [ 2.959552] vda: detected capacity change from 0 to 75063296 [ 2.981895] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.985369] vdb: detected capacity change from 0 to 1073741824 [ 3.004127] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.007125] vdc: detected capacity change from 0 to 2621440000 [ 3.020271] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.022298] vdd: detected capacity change from 0 to 2621440000 [ 3.036074] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.039019] vde: detected capacity change from 0 to 4294967296 [ 3.052319] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.054653] vdf: detected capacity change from 0 to 4294967296 [ 3.061036] libphy: Fixed MDIO Bus: probed [ 3.065398] usbcore: registered new interface driver usbserial_generic [ 3.067945] usbserial: USB Serial support registered for generic [ 3.069975] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.073346] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.074704] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.076653] mousedev: PS/2 mouse device common for all mice [ 3.079104] rtc_cmos 00:05: RTC can wake from S4 [ 3.083181] rtc_cmos 00:05: registered as rtc0 [ 3.084816] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.087711] intel_pstate: CPU model not supported [ 3.090849] hid: raw HID events driver (C) Jiri Kosina [ 3.093122] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.093570] usbcore: registered new interface driver usbhid [ 3.099182] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.099864] usbhid: USB HID core driver [ 3.103953] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.104544] drop_monitor: Initializing network drop monitor service [ 3.112813] Initializing XFRM netlink socket [ 3.114363] NET: Registered protocol family 10 [ 3.116870] Segment Routing with IPv6 [ 3.118298] NET: Registered protocol family 17 [ 3.120097] mpls_gso: MPLS GSO support [ 3.125118] RAS: Correctable Errors collector initialized. [ 3.127277] AVX version of gcm_enc/dec engaged. [ 3.128941] AES CTR mode by8 optimization enabled [ 3.199230] sched_clock: Marking stable (3199205692, 0)->(4142610387, -943404695) [ 3.203236] registered taskstats version 1 [ 3.206057] Loading compiled-in X.509 certificates [ 3.208171] zswap: loaded using pool lzo/zbud [ 3.228961] Key type big_key registered [ 3.240379] Key type encrypted registered [ 3.242020] ima: No TPM chip found, activating TPM-bypass! [ 3.243774] ima: Allocated hash algorithm: sha1 [ 3.245412] ima: No architecture policies found [ 3.247484] evm: Initialising EVM extended attributes: [ 3.249787] evm: security.selinux [ 3.251017] evm: security.ima [ 3.252137] evm: security.capability [ 3.253325] evm: HMAC attrs: 0x1 [ 3.255880] rtc_cmos 00:05: setting system clock to 2026-08-27 00:21:26 UTC (1787790086) [ 3.261249] debug: unmapping init [mem 0xffffffffbb803000-0xffffffffbb9fffff] [ 3.263514] debug: unmapping init [mem 0xffffffffba582000-0xffffffffba858fff] [ 3.271057] Write protecting the kernel read-only data: 28672k [ 3.273166] debug: unmapping init [mem 0xffffffffb8c03000-0xffffffffb8dfffff] [ 3.275409] debug: unmapping init [mem 0xffffffffb9514000-0xffffffffb95fffff] [ 3.307229] 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.314882] systemd[1]: Detected virtualization kvm. [ 3.316147] systemd[1]: Detected architecture x86-64. [ 3.317568] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.341227] systemd[1]: No hostname configured. [ 3.343075] systemd[1]: Set hostname to . [ 3.345056] random: systemd: uninitialized urandom read (16 bytes read) [ 3.347621] systemd[1]: Initializing machine ID from random generator. [ 3.466691] random: systemd: uninitialized urandom read (16 bytes read) [ 3.468789] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.472499] random: systemd: uninitialized urandom read (16 bytes read) [ 3.474631] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.479176] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. Starting Apply Kernel Variables... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Timers. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Reached target Initrd Root Device. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Sockets. Starting Journal Service... [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 3.965675] device-mapper: uevent: version 1.0.3 [ 3.967812] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.609629] virtio_net virtio0 ens2: renamed from eth0 [ 4.628295] random: fast init done [ 4.662837] scsi host0: ata_piix [ 4.684033] scsi host1: ata_piix [ 4.685554] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 4.688109] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.817406] dracut-initqueue[591]: RTNETLINK answers: File exists [ 9.757923] random: crng init done [ 9.758757] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 9.931266] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Swap. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 10.885983] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.085498] SELinux: Disabled at runtime. [ 11.142753] 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.151447] systemd[1]: Detected virtualization kvm. [ 11.153152] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 11.515154] systemd[1]: initrd-switch-root.service: Succeeded. [ 11.517496] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 11.521222] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 11.523720] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 11.526321] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 11.532828] systemd[1]: Starting Journal Service... Starting Journal Service... [ 11.541089] systemd[1]: Activating swap /dev/disk/by-label/SWAP... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Forward Password Requests to Wall Directory Watch. Mounting Kernel Debug File System... [ OK ] Created slice system-sshd\x2dkeygen.slice. [FAILED[ 11.577951] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS ] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Starting Remount Root and Kernel File Systems... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Reached target rpc_pipefs.target. Starting Apply Kernel Variables... [ OK ] Created slice system-getty.slice. Mounting POSIX Message Queue File System... [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. Mounting Huge Pages File System... [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages 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. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 11.958075] 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.149711] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 12.230655] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 12.345501] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 12.357338] EDAC sbridge: Ver: 1.1.2 [ 13.763664] Key type dns_resolver registered [ 14.057541] NFS: Registering the id_resolver key type [ 14.059472] Key type id_resolver registered [ 14.061081] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ 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... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. Starting Login Service... Starting Network Manager... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting System Logging Service... Starting Crash recovery kernel arming... [ 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 oleg214-server login: [ 63.518873] libcfs: loading out-of-tree module taints kernel. [ 63.549971] Key type ._llcrypt registered [ 63.553691] Key type .llcrypt registered [ 63.677943] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_hostid [ 80.798631] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 82.262403] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 82.279125] alg: No test for adler32 (adler32-zlib) [ 83.634911] Lustre: Lustre: Build Version: 2.17.57_50_g504224c [ 84.895734] LNet: Added LNI 192.168.202.114@tcp [8/256/0/180] [ 86.776309] Key type lgssc registered [ 88.342041] Lustre: Echo OBD driver; http://www.lustre.org/ [ 104.963568] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 122.387994] hrtimer: interrupt took 6981819 ns [ 139.837355] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 151.707244] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 151.766253] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 153.008450] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 153.031920] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 153.091351] Lustre: lustre-MDT0000: new disk, initializing [ 153.144672] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 153.158453] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 156.637523] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 167.572363] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 167.645233] Lustre: 6513:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 167.666944] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 167.668841] Lustre: Skipped 1 previous similar message [ 167.729429] Lustre: lustre-MDT0001: new disk, initializing [ 167.784545] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 167.820304] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 167.828784] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 170.745359] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 174.423553] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 184.334990] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 184.780324] Lustre: lustre-OST0000: new disk, initializing [ 184.797051] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 184.818878] Lustre: 8452:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 184.920502] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 192.434753] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 194.627725] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 194.641888] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 194.712682] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 206.154041] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 206.250697] Lustre: lustre-OST0001: new disk, initializing [ 206.254503] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 206.259616] Lustre: 9524:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 206.346459] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 213.129696] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 215.108122] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 215.129058] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 215.174918] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 223.925439] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 229.594481] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 236.089506] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing check_logdir /tmp/testlogs/ [ 240.913821] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing yml_node [ 244.069723] Lustre: DEBUG MARKER: Client: 2.17.57.50 [ 246.193208] Lustre: DEBUG MARKER: MDS: 2.17.57.50 [ 248.406343] Lustre: DEBUG MARKER: OSS: 2.17.57.50 [ 249.900130] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Wed Aug 26 20:25:32 EDT 2026 [ 265.828678] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 275.823562] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 285.673133] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 285.684470] 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 [ 285.714236] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 286.696179] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 286.697281] 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 [ 286.711808] Lustre: Skipped 2 previous similar messages [ 286.729505] Lustre: Skipped 2 previous similar messages [ 289.165694] Lustre: server umount lustre-MDT0000 complete [ 296.930612] LustreError: 6525:0:(ldlm_lib.c:1190: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. [ 296.946858] LustreError: 6525:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 8 previous similar messages [ 297.229485] LustreError: 6506:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787790380 with bad export cookie 8553116422775212769 [ 297.235250] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 297.237341] LustreError: 6506:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 297.647391] Lustre: server umount lustre-MDT0001 complete [ 316.604391] Lustre: server umount lustre-OST0000 complete [ 318.434323] Lustre: 3651:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787790385/real 1787790385] req@ffff8c244396e580 x1874633863299328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787790401 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 318.472797] 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 [ 323.552173] Lustre: 3650:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787790390/real 1787790390] req@ffff8c257f940b40 x1874633863299584/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787790406 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 324.952854] Lustre: server umount lustre-OST0001 complete [ 337.662553] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing unload_modules_local [ 340.385301] Key type lgssc unregistered [ 340.733788] LNet: 14797:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 340.741133] LNetError: 14797:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 340.758670] LNet: Removed LNI 192.168.202.114@tcp [ 341.610654] Key type .llcrypt unregistered [ 341.617201] Key type ._llcrypt unregistered [ 363.171554] Key type ._llcrypt registered [ 363.173912] Key type .llcrypt registered [ 363.287878] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_hostid [ 382.566054] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 384.475366] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 384.509568] alg: No test for adler32 (adler32-zlib) [ 385.844651] Lustre: Lustre: Build Version: 2.17.57_50_g504224c [ 386.145525] LNet: Added LNI 192.168.202.114@tcp [8/256/0/180] [ 387.816187] Key type lgssc registered [ 389.051119] Lustre: Echo OBD driver; http://www.lustre.org/ [ 439.909760] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 453.399050] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 453.444357] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 454.754790] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 454.789896] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 454.868402] Lustre: lustre-MDT0000: new disk, initializing [ 454.950528] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 454.977937] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 460.064389] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 474.707657] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 474.863174] Lustre: 19254:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 474.889320] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 474.893731] Lustre: Skipped 1 previous similar message [ 475.018524] Lustre: lustre-MDT0001: new disk, initializing [ 475.153441] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 475.182446] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 475.201355] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 479.942441] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 485.105708] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 493.952105] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 494.205818] Lustre: lustre-OST0000: new disk, initializing [ 494.212504] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 494.216898] Lustre: 21191:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 494.282341] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 494.402800] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 494.429733] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 494.584576] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 500.494441] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 512.662094] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 512.799955] Lustre: lustre-OST0001: new disk, initializing [ 512.807331] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 512.814695] Lustre: 22217:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 512.889333] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 518.156532] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 518.164393] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 518.191049] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 518.210531] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 528.993440] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 534.810510] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 542.269709] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 20:30:24 (1787790624) === [ 544.523455] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 20:30:26 (1787790626) [ 544.691925] Lustre: 19262:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 544.694566] Lustre: 19262:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 544.698557] Lustre: 19262:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 544.702504] Lustre: 19262:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 544.707742] Lustre: 19262:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 544.719239] Lustre: 19262:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 545.196108] Lustre: 21199:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 545.201016] Lustre: 21199:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 35 previous similar messages [ 545.205649] Lustre: 21199:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 545.211223] Lustre: 21199:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 545.214363] Lustre: 21199:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 545.217311] Lustre: 21199:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 545.220261] Lustre: 21199:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 545.224049] Lustre: 21199:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 545.228250] Lustre: 21199:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 545.231481] Lustre: 21199:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 545.234596] Lustre: 21199:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 545.237333] Lustre: 21199:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 546.228992] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 546.238819] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 59 previous similar messages [ 546.244438] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 546.254594] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 546.261734] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 546.265399] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 546.269657] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 546.274414] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 546.280485] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 546.284379] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 546.288464] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 546.294872] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 548.234065] Lustre: 19261:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 548.242663] Lustre: 19261:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 131 previous similar messages [ 548.251064] Lustre: 19261:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 548.264377] Lustre: 19261:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 548.278490] Lustre: 19261:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 548.288897] Lustre: 19261:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 548.297415] Lustre: 19261:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 548.309910] Lustre: 19261:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 548.320789] Lustre: 19261:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 548.332408] Lustre: 19261:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 548.345880] Lustre: 19261:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 548.350690] Lustre: 19261:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 550.430667] Lustre: *** cfs_fail_loc=1600, val=3*** [ 553.921061] Lustre: *** cfs_fail_loc=1600, val=3*** [ 555.063488] Lustre: 21181:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 555.081360] Lustre: 23804:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 555.087918] Lustre: 21181:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 52 previous similar messages [ 555.089765] Lustre: 23804:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 51 previous similar messages [ 555.089790] Lustre: 23804:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 555.089793] Lustre: 23804:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 51 previous similar messages [ 555.089799] Lustre: 23804:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 555.089803] Lustre: 23804:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 51 previous similar messages [ 555.089807] Lustre: 23804:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 555.089810] Lustre: 23804:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 51 previous similar messages [ 555.089815] Lustre: 23804:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 555.089818] Lustre: 23804:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 51 previous similar messages [ 567.265207] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 567.274051] 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 [ 567.290645] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 568.523704] Lustre: server umount lustre-MDT0000 complete [ 569.316376] 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 [ 571.838751] LustreError: 19247:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787790655 with bad export cookie 9335107139365285500 [ 571.844661] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 571.857259] LustreError: 19247:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 572.058369] Lustre: server umount lustre-MDT0001 complete [ 585.638908] Lustre: server umount lustre-OST0000 complete [ 597.938220] Lustre: server umount lustre-OST0001 complete [ 605.100929] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 20:31:27 (1787790687) [ 616.752285] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 626.469996] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 626.968954] LustreError: 26274:0:(ldlm_lib.c:1190: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. [ 626.993762] LustreError: 26274:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 5 previous similar messages [ 627.038249] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 631.193367] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 632.300249] LustreError: 26275:0:(ldlm_lib.c:1190: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. [ 632.310648] LustreError: 26275:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 637.423978] LustreError: 26274:0:(ldlm_lib.c:1190: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. [ 639.266253] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 639.615342] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 643.480118] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 646.062943] Lustre: 27412:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 652.130424] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 652.264315] LustreError: 27765:0:(ldlm_lib.c:1190: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. [ 652.284988] LustreError: 27765:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 657.891289] LustreError: 27767:0:(ldlm_lib.c:1190: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. [ 657.908067] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 658.546965] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 665.894876] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 666.034107] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 666.038978] Lustre: Skipped 1 previous similar message [ 671.218345] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:40 to 0x2c0000401:65) [ 671.686846] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 678.505094] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 681.598636] Lustre: 29282:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 683.002396] Lustre: 26271:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 683.009192] Lustre: 26271:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 57 previous similar messages [ 683.015096] Lustre: 26271:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 683.025854] Lustre: 26271:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 683.030167] Lustre: 26271:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 683.035583] Lustre: 26271:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 683.040251] Lustre: 26271:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 683.048145] Lustre: 26271:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 683.056829] Lustre: 26271:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 683.063159] Lustre: 26271:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 683.068592] Lustre: 26271:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 683.077248] Lustre: 26271:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 687.233162] Lustre: *** cfs_fail_loc=1501, val=0*** [ 694.526875] Lustre: Failing over lustre-MDT0000 [ 694.761191] Lustre: server umount lustre-MDT0000 complete [ 695.780913] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 695.789717] 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 [ 695.799744] Lustre: Skipped 2 previous similar messages [ 695.804070] LustreError: 26274:0:(ldlm_lib.c:1190: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.812100] LustreError: 26274:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 703.938795] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 704.231842] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 704.602738] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 704.669257] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 709.387389] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 709.604825] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 709.631926] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 709.709921] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 709.788144] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 709.789165] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 712.822934] Lustre: *** cfs_fail_loc=1505, val=0*** [ 719.037308] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 20:33:21 (1787790801) [ 720.213473] Lustre: 26271:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 720.219947] Lustre: 26271:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 720.225541] Lustre: 26271:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 720.230662] Lustre: 26271:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 720.237042] Lustre: 26271:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 720.242070] Lustre: 26271:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 720.248208] Lustre: 26271:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 720.253739] Lustre: 26271:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 720.257946] Lustre: 26271:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 720.262236] Lustre: 26271:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 720.265947] Lustre: 26271:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 720.270263] Lustre: 26271:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 723.979329] Lustre: *** cfs_fail_loc=1502, val=0*** [ 733.661352] Lustre: Failing over lustre-MDT0000 [ 733.926142] Lustre: server umount lustre-MDT0000 complete [ 735.202192] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 735.216942] 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 [ 735.225261] LustreError: 26269:0:(ldlm_lib.c:1190: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. [ 735.231311] Lustre: Skipped 6 previous similar messages [ 735.250651] LustreError: 26269:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 11 previous similar messages [ 745.492120] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 745.609747] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 745.885897] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 750.273509] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 751.077489] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 751.082801] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 751.110158] Lustre: Skipped 3 previous similar messages [ 751.137353] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 751.173933] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 751.177605] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 753.248281] Lustre: *** cfs_fail_loc=1505, val=0*** [ 760.413207] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 20:34:02 (1787790842) [ 761.699630] Lustre: 29048:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 761.706722] Lustre: 29048:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 761.712666] Lustre: 29048:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 761.718257] Lustre: 29048:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 761.722878] Lustre: 29048:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 761.728911] Lustre: 29048:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 761.733639] Lustre: 29048:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 761.740976] Lustre: 29048:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 761.746539] Lustre: 29048:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 761.751445] Lustre: 29048:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 761.756284] Lustre: 29048:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 761.760726] Lustre: 29048:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 766.117408] Lustre: *** cfs_fail_loc=1504, val=0*** [ 766.119494] Lustre: *** cfs_fail_loc=1504, val=0*** [ 766.131849] Lustre: Skipped 1 previous similar message [ 772.974362] Lustre: Failing over lustre-MDT0000 [ 773.225665] Lustre: server umount lustre-MDT0000 complete [ 776.673780] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 776.681705] LustreError: 26274:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 776.687700] Lustre: Skipped 3 previous similar messages [ 776.731414] LustreError: 26274:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 11 previous similar messages [ 783.828756] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 783.912190] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 784.100440] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 784.108622] Lustre: Skipped 1 previous similar message [ 784.152700] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 788.158577] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 789.479732] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 789.497637] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 789.507692] Lustre: Skipped 3 previous similar messages [ 789.528033] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 789.564577] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 789.565257] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 791.129457] Lustre: *** cfs_fail_loc=1505, val=0*** [ 797.840282] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 20:34:39 (1787790879) [ 802.781483] Lustre: *** cfs_fail_loc=1603, val=0*** [ 809.591253] Lustre: Failing over lustre-MDT0000 [ 809.785962] Lustre: server umount lustre-MDT0000 complete [ 809.957232] 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 [ 809.969655] Lustre: Skipped 2 previous similar messages [ 819.031888] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 819.208787] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 819.580687] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 823.483572] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 824.805651] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 824.816098] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 824.827392] Lustre: Skipped 3 previous similar messages [ 824.849766] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 824.924955] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 824.925125] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 831.741206] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 20:35:13 (1787790913) [ 832.929840] Lustre: 26269:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 832.943125] Lustre: 26269:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 644 previous similar messages [ 832.951478] Lustre: 26269:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 832.959670] Lustre: 26269:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 832.975642] Lustre: 26269:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 832.984231] Lustre: 26269:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 832.991410] Lustre: 26269:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 833.002623] Lustre: 26269:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 833.018263] Lustre: 26269:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 833.031891] Lustre: 26269:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 833.041685] Lustre: 26269:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 833.051231] Lustre: 26269:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 837.520505] Lustre: *** cfs_fail_loc=1604, val=0*** [ 845.245652] Lustre: Failing over lustre-MDT0000 [ 845.282521] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 845.290455] 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 [ 845.307555] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 845.310667] Lustre: Skipped 4 previous similar messages [ 845.661105] Lustre: server umount lustre-MDT0000 complete [ 850.403661] LustreError: 26270:0:(ldlm_lib.c:1190: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. [ 850.434199] LustreError: 26270:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 15 previous similar messages [ 855.899725] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 856.066718] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 856.427837] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 861.028894] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 861.666799] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 861.668515] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 861.676832] Lustre: Skipped 3 previous similar messages [ 861.703866] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 861.750461] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 861.750814] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 869.384520] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 20:35:51 (1787790951) [ 874.471285] Lustre: *** cfs_fail_loc=1605, val=0*** [ 881.896819] Lustre: Failing over lustre-MDT0000 [ 882.078732] Lustre: server umount lustre-MDT0000 complete [ 882.150909] 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 [ 882.169425] Lustre: Skipped 1 previous similar message [ 882.212231] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 892.512263] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 892.594833] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 892.845973] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 896.988903] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 898.020857] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 898.030975] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 898.035163] Lustre: Skipped 3 previous similar messages [ 898.047789] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 898.091981] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 898.092707] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 905.318470] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 20:36:27 (1787790987) [ 910.995068] Lustre: *** cfs_fail_loc=161d, val=0*** [ 918.072622] Lustre: Failing over lustre-MDT0000 [ 918.319546] Lustre: server umount lustre-MDT0000 complete [ 928.451069] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 928.558774] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 928.737570] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 928.743294] Lustre: Skipped 6 previous similar messages [ 928.856574] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 928.861788] Lustre: Skipped 3 previous similar messages [ 928.891548] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 933.013730] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 933.857328] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 933.862720] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 933.885445] Lustre: Skipped 3 previous similar messages [ 933.924015] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 933.973776] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 933.974150] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 941.353416] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 20:37:03 (1787791023) [ 943.502848] Lustre: *** cfs_fail_loc=1603, val=0*** [ 953.462037] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 20:37:15 (1787791035) [ 958.669813] Lustre: *** cfs_fail_loc=1603, val=0*** [ 959.627936] Lustre: *** cfs_fail_loc=1604, val=0*** [ 962.107912] Lustre: 38664:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 962.107912] Lustre: 29419:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 962.107922] Lustre: 29419:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1289 previous similar messages [ 962.121551] Lustre: 38664:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1289 previous similar messages [ 962.137562] Lustre: 29419:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 962.137573] Lustre: 29419:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 962.137579] Lustre: 29419:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 962.137583] Lustre: 29419:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 962.137588] Lustre: 29419:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 962.137591] Lustre: 29419:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 962.137596] Lustre: 29419:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 962.137599] Lustre: 29419:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 962.137604] Lustre: 29419:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 962.137607] Lustre: 29419:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 969.745517] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 20:37:31 (1787791051) [ 1004.044280] Lustre: Failing over lustre-MDT0000 [ 1004.345901] Lustre: server umount lustre-MDT0000 complete [ 1005.537358] 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 [ 1005.552709] Lustre: Skipped 7 previous similar messages [ 1005.556126] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1005.563231] LustreError: 29049:0:(ldlm_lib.c:1190: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. [ 1005.563243] LustreError: 29049:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 24 previous similar messages [ 1009.189583] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1017.469057] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1021.405243] Lustre: 16416:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787791088/real 1787791088] req@ffff8c255ee52580 x1874634179557248/t0(0) o400->MGC192.168.202.114@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787791104 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1021.433384] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1028.258533] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1028.270934] Lustre: lustre-MDT0000: reset Object Index mappings [ 1031.648757] LustreError: 16414:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8c2545b1a1c0 x1874634179565952/t0(0) o250->MGC192.168.202.114@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1031.956930] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1036.343294] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1037.292804] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1037.300407] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1037.310173] Lustre: Skipped 3 previous similar messages [ 1037.336110] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1037.390026] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1037.390696] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1039.602354] LustreError: 42923:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1039.618318] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1041.696833] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1041.701652] Lustre: Skipped 1 previous similar message [ 1048.661432] Lustre: Failing over lustre-MDT0000 [ 1049.171808] Lustre: server umount lustre-MDT0000 complete [ 1059.135816] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1064.340824] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1065.012938] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1065.013261] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1067.653597] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1075.764724] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 20:39:17 (1787791157) [ 1078.198359] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1086.758658] Lustre: Failing over lustre-MDT0000 [ 1087.000426] Lustre: server umount lustre-MDT0000 complete [ 1092.456994] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1102.440050] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1106.917214] Lustre: 16415:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787791173/real 1787791173] req@ffff8c24439fc000 x1874634179653888/t0(0) o400->MGC192.168.202.114@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787791189 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1112.978296] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1113.007331] Lustre: lustre-MDT0000: reset Object Index mappings [ 1117.155863] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x818cf67bd6170805 [ 1117.177471] Lustre: MGC192.168.202.114@tcp: Connection restored to 0@lo (at 0@lo) [ 1117.184485] Lustre: Skipped 7 previous similar messages [ 1117.471859] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1117.484326] Lustre: Skipped 1 previous similar message [ 1121.109938] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1122.801189] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1122.816063] Lustre: Skipped 1 previous similar message [ 1122.847023] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1122.857526] Lustre: Skipped 1 previous similar message [ 1122.922817] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1122.932043] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1124.524569] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1124.534431] Lustre: Skipped 2 previous similar messages [ 1132.776021] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1132.785901] Lustre: Skipped 7 previous similar messages [ 1140.020948] Lustre: Failing over lustre-MDT0000 [ 1140.295581] Lustre: server umount lustre-MDT0000 complete [ 1143.284541] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1143.286178] 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 [ 1143.320143] Lustre: Skipped 9 previous similar messages [ 1150.530418] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1150.641197] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1150.654723] LustreError: Skipped 2 previous similar messages [ 1155.477853] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1156.150976] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1156.154592] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1158.845065] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1158.848081] Lustre: Skipped 84 previous similar messages [ 1166.100094] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 20:40:48 (1787791248) [ 1171.997861] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1172.000754] Lustre: Skipped 1 previous similar message [ 1189.397768] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 20:41:11 (1787791271) [ 1206.782587] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1206.790859] Lustre: Skipped 16 previous similar messages [ 1219.813735] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 20:41:41 (1787791301) [ 1221.332648] Lustre: 26270:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1221.338263] Lustre: 26270:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1415 previous similar messages [ 1221.343241] Lustre: 26270:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1221.348587] Lustre: 26270:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1416 previous similar messages [ 1221.353522] Lustre: 26270:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1221.360890] Lustre: 26270:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1415 previous similar messages [ 1221.366611] Lustre: 26270:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 1221.373209] Lustre: 26270:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1416 previous similar messages [ 1221.378722] Lustre: 26270:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1221.384536] Lustre: 26270:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1415 previous similar messages [ 1234.127259] Lustre: Failing over lustre-MDT0000 [ 1234.318676] Lustre: server umount lustre-MDT0000 complete [ 1237.986209] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1243.219131] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1243.492245] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1243.498077] Lustre: Skipped 4 previous similar messages [ 1248.415651] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1248.748986] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1248.752991] Lustre: Skipped 8 previous similar messages [ 1248.799633] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:854 to 0x280000401:897) [ 1248.800487] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 1256.970556] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 20:42:19 (1787791339) [ 1270.583343] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 1286.801230] Lustre: 52934:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1307.572770] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1311.417850] Lustre: 54071:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1318.563499] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1318.568549] Lustre: Skipped 81 previous similar messages [ 1321.055524] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1322.080950] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1323.106785] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1325.155292] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1325.156966] Lustre: Skipped 1 previous similar message [ 1326.007323] Lustre: Failing over lustre-MDT0000 [ 1326.188508] Lustre: server umount lustre-MDT0000 complete [ 1330.656893] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1330.661370] LustreError: 26270:0:(ldlm_lib.c:1190: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. [ 1330.698287] LustreError: 26270:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 82 previous similar messages [ 1336.825327] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1337.155257] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1337.164788] Lustre: Skipped 2 previous similar messages [ 1342.370420] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1342.446812] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1342.460666] Lustre: Skipped 2 previous similar messages [ 1342.476922] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1342.486628] Lustre: Skipped 2 previous similar messages [ 1342.602227] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1342.609394] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1351.659602] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 20:43:53 (1787791433) [ 1357.794573] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1357.799611] Lustre: Skipped 3 previous similar messages [ 1361.802960] Lustre: server umount lustre-MDT0000 complete [ 1365.873799] LustreError: 26254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787791449 with bad export cookie 9335107139365499791 [ 1365.889212] LustreError: 26254:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1366.168461] Lustre: server umount lustre-MDT0001 complete [ 1380.258781] Lustre: server umount lustre-OST0000 complete [ 1393.926168] Lustre: server umount lustre-OST0001 complete [ 1400.731467] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_hostid [ 1407.901586] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 1446.848955] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 1457.210737] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1457.559621] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1457.611596] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1457.718326] Lustre: lustre-MDT0000: new disk, initializing [ 1457.797858] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1461.948591] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1471.769469] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1471.845541] Lustre: 59133:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1471.870767] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1471.875182] Lustre: Skipped 1 previous similar message [ 1471.948418] Lustre: lustre-MDT0001: new disk, initializing [ 1472.071981] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1472.078724] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1476.338989] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1480.761291] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1486.374234] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1486.552369] Lustre: lustre-OST0000: new disk, initializing [ 1486.555519] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1486.561918] Lustre: 60763:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1488.420528] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1488.433683] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1488.471333] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1492.580493] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1502.135037] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1502.275131] Lustre: lustre-OST0001: new disk, initializing [ 1502.279835] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1502.285915] Lustre: 61632:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1503.784955] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1503.793923] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1503.823192] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1508.223444] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1516.520580] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1519.633900] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1519.836593] Lustre: 59139:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 1519.846904] Lustre: 59139:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2185 previous similar messages [ 1527.197227] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1527.926418] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1527.927916] Lustre: Skipped 19 previous similar messages [ 1531.527358] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1531.529807] Lustre: Skipped 10 previous similar messages [ 1546.278603] Lustre: Failing over lustre-MDT0000 [ 1546.811269] Lustre: server umount lustre-MDT0000 complete [ 1548.768388] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1548.770482] 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 [ 1548.782595] Lustre: Skipped 15 previous similar messages [ 1555.147257] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1555.268952] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1555.285563] LustreError: Skipped 3 previous similar messages [ 1560.521244] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1560.552360] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1560.562241] Lustre: Skipped 7 previous similar messages [ 1560.652978] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1560.666253] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1560.667511] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1568.648547] Lustre: Failing over lustre-MDT0000 [ 1568.958732] Lustre: server umount lustre-MDT0000 complete [ 1577.030783] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1581.999675] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1582.615436] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1582.632402] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1582.633595] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1586.257213] Lustre: Failing over lustre-MDT0000 [ 1586.413248] Lustre: server umount lustre-MDT0000 complete [ 1595.033493] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1595.398460] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1595.410178] Lustre: Skipped 2 previous similar messages [ 1599.577296] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1600.482462] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1600.494124] Lustre: Skipped 2 previous similar messages [ 1600.522305] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1600.529513] Lustre: Skipped 2 previous similar messages [ 1600.553393] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1600.553535] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1603.996480] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1612.975677] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 20:48:15 (1787791695) [ 1626.478789] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 1643.614183] Lustre: 68536:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1664.986654] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1761.737812] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 20:50:43 (1787791843) [ 1796.857152] Lustre: 59139:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 1796.861548] Lustre: 59139:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1796.867419] Lustre: 59139:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1796.873412] Lustre: 59139:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1796.877888] Lustre: 59139:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 1796.882502] Lustre: 59139:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1796.887792] Lustre: 59139:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1796.892649] Lustre: 59139:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1796.898249] Lustre: 59139:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1796.903438] Lustre: 59139:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1800.769049] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1800.772870] Lustre: Skipped 4 previous similar messages [ 1821.913811] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1821.915717] Lustre: Skipped 7 previous similar messages [ 1856.605774] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 20:52:18 (1787791938) [ 1890.275400] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1898.290905] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1898.293566] Lustre: Skipped 554 previous similar messages [ 1914.322895] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1914.325687] Lustre: Skipped 1231 previous similar messages [ 1940.274850] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1940.276385] Lustre: Skipped 2599 previous similar messages [ 2125.940796] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 20:56:48 (1787792208) [ 2138.529260] Lustre: 69821:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 320, rollback = 2 [ 2138.532310] Lustre: 69821:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 38084 previous similar messages [ 2243.430559] Lustre: server umount lustre-MDT0000 complete [ 2245.602540] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2245.613384] LustreError: Skipped 2 previous similar messages [ 2245.615803] 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 [ 2245.625557] Lustre: Skipped 11 previous similar messages [ 2245.630427] LustreError: 60608:0:(ldlm_lib.c:1190: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. [ 2245.645352] LustreError: 60608:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 36 previous similar messages [ 2246.755715] LustreError: 59123:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787792329 with bad export cookie 9335107139365518894 [ 2246.761485] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2246.769732] LustreError: 59123:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2246.797398] LustreError: Skipped 2 previous similar messages [ 2247.101905] Lustre: server umount lustre-MDT0001 complete [ 2261.453918] Lustre: server umount lustre-OST0000 complete [ 2274.019117] Lustre: server umount lustre-OST0001 complete [ 2279.882514] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2286.846291] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2302.368507] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2307.489438] LustreError: 74937:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.114@tcp: failed processing log, type 4: rc = -110 [ 2333.280250] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2333.287602] Lustre: Skipped 8 previous similar messages [ 2338.525802] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2341.505385] Lustre: 75521:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2341.538889] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2344.618615] Lustre: 75521:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2352.165975] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 21:00:34 (1787792434) [ 2363.611280] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 2375.380286] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2376.025682] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2380.619505] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2388.520980] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2393.068743] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2395.792625] Lustre: 78200:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2395.797430] Lustre: 78200:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2408.998632] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2414.587054] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2415.410539] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2423.263673] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2426.235716] Lustre: 79695:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2427.357853] Lustre: 78017:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2427.366396] Lustre: 78017:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 22020 previous similar messages [ 2427.371616] Lustre: 78017:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2427.379659] Lustre: 78017:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 22020 previous similar messages [ 2427.385286] Lustre: 78017:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2427.391933] Lustre: 78017:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2427.398580] Lustre: 78017:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2427.409151] Lustre: 78017:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2427.414936] Lustre: 78017:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2427.422085] Lustre: 78017:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 22020 previous similar messages [ 2431.376181] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2439.203708] Lustre: Failing over lustre-OST0000 [ 2439.371384] Lustre: server umount lustre-OST0000 complete [ 2447.492243] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2447.619224] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2449.127154] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2449.153756] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2449.157393] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2449.159390] Lustre: *** cfs_fail_loc=215, val=0*** [ 2449.160623] Lustre: Skipped 11 previous similar messages [ 2453.127444] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2454.498852] Lustre: *** cfs_fail_loc=215, val=0*** [ 2454.503433] Lustre: Skipped 2 previous similar messages [ 2456.821872] Lustre: 81096:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2456.833735] Lustre: 81096:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2459.521276] Lustre: Failing over lustre-OST0000 [ 2459.609346] Lustre: server umount lustre-OST0000 complete [ 2468.088463] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2469.582701] Lustre: *** cfs_fail_loc=215, val=0*** [ 2469.595704] Lustre: Skipped 2 previous similar messages [ 2474.976582] Lustre: *** cfs_fail_loc=215, val=0*** [ 2474.979364] Lustre: Skipped 1 previous similar message [ 2476.371192] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2480.096988] Lustre: *** cfs_fail_loc=215, val=0*** [ 2480.102779] Lustre: Skipped 1 previous similar message [ 2483.687571] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2488.765725] Lustre: server umount lustre-MDT0000 complete [ 2492.141107] LustreError: 74945:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787792575 with bad export cookie 9335107139367084290 [ 2492.151252] LustreError: 74945:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2492.427854] Lustre: server umount lustre-MDT0001 complete [ 2505.847694] Lustre: server umount lustre-OST0000 complete [ 2509.792099] Lustre: 16415:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787792577/real 1787792577] req@ffff8c255d54e1c0 x1874634183782016/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787792593 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2510.452915] Lustre: server umount lustre-OST0001 complete [ 2520.664387] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 21:03:21 (1787792601) [ 2535.731690] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 2546.605835] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2554.564485] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2563.447201] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2568.129241] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2570.953661] Lustre: 85478:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2577.228321] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2583.538364] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2591.546657] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2592.743785] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 2592.760950] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 2598.728509] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2608.345424] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2612.165897] Lustre: 87347:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2670.311588] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 21:05:52 (1787792752) [ 2683.349924] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 21:06:05 (1787792765) [ 2684.705765] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2695.927420] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 21:06:17 (1787792777) [ 2700.035143] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2700.046129] Lustre: Skipped 7 previous similar messages [ 2748.388278] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2748.397145] Lustre: Skipped 3 previous similar messages [ 2751.459962] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2751.474445] Lustre: Skipped 3 previous similar messages [ 2753.227461] Lustre: server umount lustre-MDT0000 complete [ 2757.039131] LustreError: 84316:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787792840 with bad export cookie 9335107139367092781 [ 2757.046212] LustreError: 84316:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2757.262469] Lustre: server umount lustre-MDT0001 complete [ 2770.053779] Lustre: server umount lustre-OST0000 complete [ 2784.435793] Lustre: server umount lustre-OST0001 complete [ 2798.574840] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 2807.403232] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2811.994975] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2822.575637] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2830.882774] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2834.908416] Lustre: 94072:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2842.595800] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2848.163587] LustreError: 94427:0:(ldlm_lib.c:1190: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. [ 2848.175663] LustreError: 94427:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 40 previous similar messages [ 2848.212330] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 2848.411446] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2853.299520] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 2855.514879] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2861.054516] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 2861.055842] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 2861.913289] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2868.950665] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2879.206601] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 21:09:21 (1787792961) [ 2881.512057] Lustre: 95091:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 2881.528907] Lustre: 95091:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1361 previous similar messages [ 2885.390557] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2885.393156] Lustre: Skipped 63 previous similar messages [ 2912.227682] 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 [ 2912.250527] Lustre: Skipped 16 previous similar messages [ 2912.255724] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2912.271889] Lustre: Skipped 3 previous similar messages [ 2917.356407] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2917.779843] Lustre: server umount lustre-MDT0000 complete [ 2922.229475] LustreError: 95250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787793005 with bad export cookie 9335107139367121194 [ 2922.233527] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2922.241440] LustreError: 95250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2922.250436] LustreError: Skipped 2 previous similar messages [ 2922.774447] Lustre: server umount lustre-MDT0001 complete [ 2929.248198] Lustre: server umount lustre-OST0000 complete [ 2933.156681] Lustre: server umount lustre-OST0001 complete [ 2951.096978] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 2963.088393] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2963.578358] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2963.582835] Lustre: Skipped 13 previous similar messages [ 2970.764618] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2983.272440] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2989.292793] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2992.652315] Lustre: 99970:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2992.656971] Lustre: 99970:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2999.502744] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3006.178875] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3008.258812] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3009.265166] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3016.985622] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3022.330864] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3022.500478] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3025.882308] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3034.895146] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3046.475969] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 21:12:08 (1787793128) [ 3047.953365] Lustre: 101800:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3047.960789] Lustre: 101800:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1496 previous similar messages [ 3047.969300] Lustre: 101800:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3047.974493] Lustre: 101800:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1496 previous similar messages [ 3047.979907] Lustre: 101800:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3047.985498] Lustre: 101800:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1496 previous similar messages [ 3047.997443] Lustre: 101800:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3048.002960] Lustre: 101800:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1496 previous similar messages [ 3048.008598] Lustre: 101800:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3048.013327] Lustre: 101800:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1496 previous similar messages [ 3049.549931] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3049.552251] Lustre: Skipped 63 previous similar messages [ 3049.789149] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3061.591746] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 21:12:23 (1787793143) [ 3064.073928] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3064.175781] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3064.177594] Lustre: Skipped 2 previous similar messages [ 3075.225752] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 21:12:37 (1787793157) [ 3077.053407] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3078.967122] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 21:12:40 (1787793160) [ 3084.732762] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3084.734916] LustreError: 98839:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3084.750068] LustreError: 98839:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s90 failed: rc = -5 [ 3152.877096] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3152.881314] LustreError: Skipped 4 previous similar messages [ 3152.890451] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3152.900277] Lustre: Skipped 5 previous similar messages [ 3158.350542] Lustre: server umount lustre-MDT0000 complete [ 3168.180265] LustreError: 98811:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787793251 with bad export cookie 9335107139367135929 [ 3168.198255] LustreError: 98811:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3168.434443] Lustre: server umount lustre-MDT0001 complete [ 3187.170742] Lustre: 16418:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787793254/real 1787793254] req@ffff8c256bb38780 x1874634184795648/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787793270 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3187.411858] Lustre: server umount lustre-OST0000 complete [ 3190.048171] Lustre: 16416:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787793257/real 1787793257] req@ffff8c256bb38000 x1874634184795904/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787793273 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3192.291987] Lustre: 16417:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787793259/real 1787793259] req@ffff8c2544a04f00 x1874634184796160/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787793275 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3194.338787] Lustre: 16415:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787793261/real 1787793261] req@ffff8c244207bc00 x1874634184796544/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787793277 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3197.247038] Lustre: server umount lustre-OST0001 complete [ 3213.887574] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing unload_modules_local [ 3216.865634] Key type lgssc unregistered [ 3217.189876] LNet: 105684:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3217.193479] LNetError: 105684:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3217.201987] LNet: Removed LNI 192.168.202.114@tcp [ 3218.285353] Key type .llcrypt unregistered [ 3218.290268] Key type ._llcrypt unregistered [ 3244.055713] Key type ._llcrypt registered [ 3244.064516] Key type .llcrypt registered [ 3244.218579] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_hostid [ 3257.937733] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 3259.401156] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3259.425602] alg: No test for adler32 (adler32-zlib) [ 3260.583223] Lustre: Lustre: Build Version: 2.17.57_50_g504224c [ 3260.892905] LNet: Added LNI 192.168.202.114@tcp [8/256/0/180] [ 3262.624213] Key type lgssc registered [ 3264.252095] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3317.315509] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 3332.664102] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3332.688907] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3334.033420] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3334.124667] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3334.247267] Lustre: lustre-MDT0000: new disk, initializing [ 3334.392993] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3334.422561] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3339.554511] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3351.897067] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3352.021872] Lustre: 110121:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3352.053941] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3352.058537] Lustre: Skipped 1 previous similar message [ 3352.196378] Lustre: lustre-MDT0001: new disk, initializing [ 3352.270842] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3352.305293] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3352.317133] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3357.767845] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3363.499138] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3376.598815] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3376.800954] Lustre: lustre-OST0000: new disk, initializing [ 3376.803214] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3376.809562] Lustre: 112061:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3376.866680] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3383.824536] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3385.408505] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3385.439636] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3385.557452] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3397.879403] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3398.071471] Lustre: lustre-OST0001: new disk, initializing [ 3398.075431] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3398.082904] Lustre: 113086:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3398.169392] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3404.221451] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3404.338596] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3404.361163] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3404.425840] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3417.014260] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3427.692857] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3435.299055] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 21:18:36 (1787793516) === [ 3443.541546] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 21:18:45 (1787793525) [ 3443.932751] Lustre: 110128:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3443.945339] Lustre: 110128:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3443.954605] Lustre: 110128:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3443.963663] Lustre: 110128:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3443.973498] Lustre: 110128:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3443.982564] Lustre: 110128:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3444.603873] Lustre: 112049:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 3444.618812] Lustre: 112049:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 5 previous similar messages [ 3444.629388] Lustre: 112049:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3444.642282] Lustre: 112049:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3444.654949] Lustre: 112049:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 3444.664027] Lustre: 112049:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3444.669238] Lustre: 112049:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 3444.678735] Lustre: 112049:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3444.689672] Lustre: 112049:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3444.698025] Lustre: 112049:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3444.714519] Lustre: 112049:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3444.727967] Lustre: 112049:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3445.621871] Lustre: 112946:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3445.633468] Lustre: 112946:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 99 previous similar messages [ 3445.644614] Lustre: 112946:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3445.658161] Lustre: 112946:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 3445.683539] Lustre: 112946:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3445.691891] Lustre: 112946:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 3445.706119] Lustre: 112946:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3445.724919] Lustre: 112946:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 3445.735369] Lustre: 112946:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3445.747216] Lustre: 112946:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 3445.756279] Lustre: 112946:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3445.770178] Lustre: 112946:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 3448.245178] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3460.028091] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 21:19:01 (1787793541) [ 3461.151748] Lustre: 110127:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3461.158372] Lustre: 110127:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 203 previous similar messages [ 3461.163421] Lustre: 110127:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 3461.169539] Lustre: 110127:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 3461.178744] Lustre: 110127:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3461.183355] Lustre: 110127:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 3461.187976] Lustre: 110127:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3461.194043] Lustre: 110127:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 3461.198626] Lustre: 110127:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3461.203342] Lustre: 110127:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 3461.208525] Lustre: 110127:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3461.215212] Lustre: 110127:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 3462.272045] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3462.802538] Lustre: *** cfs_fail_loc=1614, val=103*** [ 3462.809662] Lustre: Skipped 1 previous similar message [ 3468.169867] Lustre: 112051:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3468.193155] Lustre: 112051:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3468.215194] Lustre: 112051:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3468.234416] Lustre: 112051:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3468.256401] Lustre: 112051:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3468.272856] Lustre: 112051:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3468.287547] Lustre: 112051:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3468.304542] Lustre: 112051:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3468.323180] Lustre: 112051:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3468.333980] Lustre: 112051:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3468.345313] Lustre: 112051:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3468.354689] Lustre: 112051:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3476.742449] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 21:19:18 (1787793558) [ 3477.143692] Lustre: 112946:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3477.150211] Lustre: 112946:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1 previous similar message [ 3477.158234] Lustre: 112946:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3477.168207] Lustre: 112946:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3477.173354] Lustre: 112946:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3477.177216] Lustre: 112946:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3477.180727] Lustre: 112946:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3477.187248] Lustre: 112946:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3477.193606] Lustre: 112946:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3477.198675] Lustre: 112946:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3477.202902] Lustre: 112946:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3477.206840] Lustre: 112946:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3479.909248] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3479.914730] Lustre: Skipped 1 previous similar message [ 3481.075655] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3481.083028] Lustre: Skipped 1 previous similar message [ 3500.597496] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3502.721448] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 21:19:44 (1787793584) [ 3503.139623] Lustre: 110128:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3503.146964] Lustre: 110128:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3503.156345] Lustre: 110128:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3503.163549] Lustre: 110128:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3503.173556] Lustre: 110128:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3503.180571] Lustre: 110128:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3503.192662] Lustre: 110128:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3503.207424] Lustre: 110128:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3503.217725] Lustre: 110128:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3503.224476] Lustre: 110128:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3503.233418] Lustre: 110128:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3503.242582] Lustre: 110128:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3505.403450] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3505.456035] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3508.046439] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3508.049391] Lustre: Skipped 3 previous similar messages [ 3528.965843] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 21:20:10 (1787793610) [ 3531.268941] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3531.275028] Lustre: Skipped 5 previous similar messages [ 3567.588346] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3567.598398] 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 [ 3567.622625] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3571.760529] Lustre: server umount lustre-MDT0000 complete [ 3576.273545] LustreError: 111070:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787793659 with bad export cookie 5981814237265787729 [ 3576.277595] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3576.291357] LustreError: 111070:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 3576.988163] Lustre: server umount lustre-MDT0001 complete [ 3591.480342] Lustre: server umount lustre-OST0000 complete [ 3594.528741] Lustre: 107282:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787793661/real 1787793661] req@ffff8c244b0e1a40 x1874637193697664/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787793677 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3594.553685] 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 [ 3594.564860] Lustre: Skipped 3 previous similar messages [ 3595.153225] Lustre: server umount lustre-OST0001 complete [ 3616.459696] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 3627.488822] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3627.797757] LustreError: 118799:0:(ldlm_lib.c:1190: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. [ 3627.805531] LustreError: 118799:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 5 previous similar messages [ 3627.882727] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3633.125984] LustreError: 118800:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3633.222672] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3638.241026] LustreError: 118799:0:(ldlm_lib.c:1190: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. [ 3644.386261] LustreError: 118800:0:(ldlm_lib.c:1190: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. [ 3644.409324] LustreError: 118800:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 3644.519645] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3644.949738] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3650.801747] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3654.303137] Lustre: 119940:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3661.483177] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3661.776856] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3668.233808] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3669.989446] LustreError: 120294:0:(ldlm_lib.c:1190: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. [ 3670.012912] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3674.105902] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3679.213326] LustreError: 120294:0:(ldlm_lib.c:1190: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. [ 3679.247924] LustreError: 120294:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 3679.889360] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3685.376686] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3685.445369] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3687.605811] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3696.542853] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3700.103851] Lustre: 121811:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3716.915908] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 21:23:18 (1787793798) [ 3717.320564] Lustre: 118794:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3717.334152] Lustre: 118794:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 46 previous similar messages [ 3717.338864] Lustre: 118794:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3717.342854] Lustre: 118794:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3717.346982] Lustre: 118794:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3717.350857] Lustre: 118794:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3717.356799] Lustre: 118794:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 3717.366931] Lustre: 118794:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3717.372395] Lustre: 118794:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3717.376025] Lustre: 118794:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3717.380308] Lustre: 118794:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3717.385829] Lustre: 118794:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 3719.192404] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3719.196627] Lustre: Skipped 3 previous similar messages [ 3752.416889] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3752.433686] 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 [ 3752.448875] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3752.459266] Lustre: Skipped 4 previous similar messages [ 3757.029555] 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 [ 3757.034473] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3757.047048] Lustre: Skipped 2 previous similar messages [ 3757.069622] Lustre: Skipped 3 previous similar messages [ 3758.582777] Lustre: server umount lustre-MDT0000 complete [ 3761.981218] LustreError: 118782:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787793845 with bad export cookie 5981814237265803003 [ 3761.984612] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3761.989333] LustreError: 118782:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3762.145727] 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 [ 3762.145852] LustreError: 121577:0:(ldlm_lib.c:1190: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. [ 3762.154496] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3762.176880] LustreError: 121577:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 3762.216650] Lustre: Skipped 1 previous similar message [ 3762.463950] Lustre: server umount lustre-MDT0001 complete [ 3768.616468] Lustre: server umount lustre-OST0000 complete [ 3772.592454] Lustre: server umount lustre-OST0001 complete [ 3790.927824] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 3802.890376] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3803.340996] LustreError: 124379:0:(ldlm_lib.c:1190: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. [ 3803.490727] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3803.499981] Lustre: Skipped 1 previous similar message [ 3808.531667] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3818.353297] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3823.711343] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3826.998649] Lustre: 125518:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3834.206250] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3841.009682] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3842.832692] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3847.914242] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3850.680957] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3856.365267] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3856.481393] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3858.137621] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3866.728647] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3871.343799] Lustre: 127388:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3878.125198] Lustre: 127641:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3878.136830] Lustre: 127641:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3878.152556] Lustre: 127641:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3878.172697] Lustre: 127641:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3878.186743] Lustre: 127641:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3878.200211] Lustre: 127641:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3878.219074] Lustre: 127641:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3878.244457] Lustre: 127641:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3878.257503] Lustre: 127641:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3878.275165] Lustre: 127641:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3878.290334] Lustre: 127641:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3878.310601] Lustre: 127641:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3878.385938] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3905.715218] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 21:26:27 (1787793987) [ 3909.635053] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3909.644190] Lustre: Skipped 3 previous similar messages [ 3917.655549] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3917.662071] Lustre: Skipped 1 previous similar message [ 3938.811227] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 21:27:00 (1787794020) [ 3940.644835] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3955.066824] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 21:27:17 (1787794037) [ 3958.435991] Lustre: *** cfs_fail_loc=162f, val=0*** [ 3958.437731] Lustre: Skipped 9 previous similar messages [ 3975.153479] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 21:27:37 (1787794057) [ 3987.071469] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 21:27:48 (1787794068) [ 3990.668737] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3990.717709] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3990.721525] Lustre: Skipped 3 previous similar messages [ 3995.765524] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.14@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 3996.853563] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.14@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 4005.798449] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 21:28:07 (1787794087) [ 4006.220457] Lustre: 127868:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 4006.227405] Lustre: 127868:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 107 previous similar messages [ 4006.237280] Lustre: 127868:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 4006.249271] Lustre: 127868:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 4006.255464] Lustre: 127868:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4006.261402] Lustre: 127868:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 4006.266664] Lustre: 127868:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4006.272701] Lustre: 127868:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 4006.278616] Lustre: 127868:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4006.282571] Lustre: 127868:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 4006.360296] Lustre: 127869:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4006.368654] Lustre: 127869:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 110 previous similar messages [ 4032.847627] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 21:28:34 (1787794114) [ 4039.596503] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 21:28:41 (1787794121) [ 4051.467397] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 21:28:53 (1787794133) [ 4053.115580] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4053.123001] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4053.129596] Lustre: Skipped 1 previous similar message [ 4064.901660] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 21:29:06 (1787794146) [ 4066.956852] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4066.964436] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4079.174153] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 21:29:21 (1787794161) [ 4080.712832] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4094.088436] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4095.833104] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 21:29:37 (1787794177) [ 4102.433370] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4102.434924] Lustre: Skipped 1 previous similar message [ 4105.365791] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4125.544306] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 21:30:07 (1787794207) [ 4127.782651] Lustre: Failing over lustre-MDT0000 [ 4128.235321] Lustre: server umount lustre-MDT0000 complete [ 4129.879702] LustreError: 127869:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4129.894242] LustreError: 127869:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 6 previous similar messages [ 4130.785129] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4130.800719] 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 [ 4130.815480] Lustre: Skipped 1 previous similar message [ 4138.119086] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4138.263271] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4138.611598] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4138.614593] Lustre: Skipped 3 previous similar messages [ 4138.654659] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4140.600036] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4143.658772] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4144.122532] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4144.218211] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4144.289709] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4144.293502] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4145.581218] LustreError: 126179:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4155.843752] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 21:30:37 (1787794237) [ 4157.256025] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4157.399157] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4157.401820] Lustre: Skipped 1 previous similar message [ 4168.590058] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 21:30:49 (1787794249) [ 4170.309642] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4182.203732] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 21:31:03 (1787794263) [ 4184.219824] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4196.013894] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 21:31:18 (1787794278) [ 4209.337701] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 21:31:31 (1787794291) [ 4210.866604] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4210.868485] Lustre: Skipped 1 previous similar message [ 4222.271116] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 21:31:43 (1787794303) [ 4234.735543] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 21:31:56 (1787794316) [ 4241.294117] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4256.425915] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 21:32:18 (1787794338) [ 4258.210810] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4258.215918] Lustre: Skipped 4 previous similar messages [ 4270.218304] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 21:32:31 (1787794351) [ 4270.518365] Lustre: 127869:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 320, rollback = 2 [ 4270.525146] Lustre: 127869:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 526 previous similar messages [ 4270.529588] Lustre: 127869:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 1/4/0 [ 4270.534800] Lustre: 127869:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 526 previous similar messages [ 4270.538830] Lustre: 127869:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 5/5/1, xattr_set: 7/320/0 [ 4270.544756] Lustre: 127869:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 526 previous similar messages [ 4270.549266] Lustre: 127869:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 6/46/0, punch: 0/0/0, quota 1/3/0 [ 4270.553719] Lustre: 127869:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 526 previous similar messages [ 4270.559030] Lustre: 127869:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 2/5/1 [ 4270.562728] Lustre: 127869:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 526 previous similar messages [ 4270.567136] Lustre: 127869:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/1 [ 4270.571223] Lustre: 127869:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 523 previous similar messages [ 4298.518144] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 21:33:00 (1787794380) [ 4301.010251] LustreError: 124375:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4311.482705] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 21:33:12 (1787794392) [ 4332.695574] Lustre: Failing over lustre-MDT0000 [ 4333.205383] Lustre: server umount lustre-MDT0000 complete [ 4333.551136] 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 [ 4333.566588] LustreError: 126179:0:(ldlm_lib.c:1190: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. [ 4333.573185] Lustre: Skipped 4 previous similar messages [ 4333.594169] LustreError: 126179:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 11 previous similar messages [ 4345.572047] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4345.693560] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4345.931155] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4345.974399] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4350.954652] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4350.960456] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4350.974486] Lustre: Skipped 3 previous similar messages [ 4351.011809] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4351.070251] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 4351.075544] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 4351.630516] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4366.803698] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 21:34:08 (1787794448) [ 4381.958421] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 21:34:23 (1787794463) [ 4399.107757] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 21:34:40 (1787794480) [ 4400.668077] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4400.672044] Lustre: Skipped 7 previous similar messages [ 4413.934708] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 21:34:55 (1787794495) [ 4420.462389] Lustre: Failing over lustre-MDT0000 [ 4420.836400] Lustre: server umount lustre-MDT0000 complete [ 4422.625322] 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 [ 4422.639739] Lustre: Skipped 4 previous similar messages [ 4429.996967] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4430.211257] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4430.488908] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4434.942583] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4435.942355] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4435.971873] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4435.980879] Lustre: Skipped 3 previous similar messages [ 4436.021115] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4436.085445] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 4436.086419] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 4444.726361] Lustre: Failing over lustre-MDT0000 [ 4445.071266] Lustre: server umount lustre-MDT0000 complete [ 4455.061048] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4455.348740] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4455.805304] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4458.039400] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4461.042185] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4461.051657] Lustre: Skipped 3 previous similar messages [ 4461.102429] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 4461.180573] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 4461.181892] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 4461.572869] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4471.222086] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 21:35:52 (1787794552) [ 4483.733688] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 21:36:05 (1787794565) [ 4495.951496] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 21:36:17 (1787794577) [ 4536.767124] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 21:36:58 (1787794618) [ 4538.719221] Lustre: *** cfs_fail_loc=162c, val=0*** [ 4538.732361] Lustre: Skipped 13 previous similar messages [ 4553.575547] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 21:37:15 (1787794635) [ 4561.543271] LustreError: 148739:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4564.015585] Lustre: Failing over lustre-OST0000 [ 4564.123344] Lustre: server umount lustre-OST0000 complete [ 4564.624986] LustreError: 148739:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4564.651734] LustreError: 148739:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4564.960593] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4564.973521] 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 [ 4564.998527] Lustre: Skipped 5 previous similar messages [ 4567.117962] LustreError: 148739:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4579.995733] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4580.283287] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4581.554337] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4581.592870] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4581.594708] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4581.634038] Lustre: Skipped 3 previous similar messages [ 4587.808457] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4596.461186] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 21:37:58 (1787794678) [ 4612.234893] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 4631.311638] Lustre: 151543:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4654.296088] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4658.395057] Lustre: 152688:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4668.802181] LustreError: 152804:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4671.725895] Lustre: Failing over lustre-MDT0001 [ 4671.840257] LustreError: 152804:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4671.897684] LustreError: 152803:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4671.900243] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 4671.924954] LustreError: 152803:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4671.960041] LustreError: Skipped 1 previous similar message [ 4671.969487] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4672.227835] Lustre: server umount lustre-MDT0001 complete [ 4672.481965] LustreError: 125883:0:(ldlm_lib.c:1190: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. [ 4672.501759] LustreError: 125883:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 36 previous similar messages [ 4674.993827] LustreError: 152803:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4675.017118] LustreError: 152803:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4688.313719] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4688.536994] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4688.542804] Lustre: Skipped 3 previous similar messages [ 4688.561567] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4693.602412] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4694.013235] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4694.020390] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4694.041798] Lustre: Skipped 1 previous similar message [ 4694.065744] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4694.162970] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 4694.179212] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 4703.730325] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 21:39:45 (1787794785) [ 4723.926872] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 4742.725586] Lustre: 155527:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4768.160624] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4772.008399] Lustre: 156662:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4782.647093] Lustre: 125878:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 4782.647674] Lustre: 125879:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 4782.659441] Lustre: 125878:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1534 previous similar messages [ 4782.659461] Lustre: 125878:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 4782.659463] Lustre: 125878:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1533 previous similar messages [ 4782.659467] Lustre: 125878:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 4782.659469] Lustre: 125878:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1533 previous similar messages [ 4782.659473] Lustre: 125878:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 4782.659475] Lustre: 125878:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1533 previous similar messages [ 4782.659478] Lustre: 125878:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4782.659480] Lustre: 125878:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1533 previous similar messages [ 4782.776924] Lustre: 125879:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1557 previous similar messages [ 4793.330908] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 21:41:15 (1787794875) [ 4794.883639] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 4796.642476] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 21:41:18 (1787794878) [ 4802.420142] Lustre: *** cfs_fail_loc=1631, val=0*** [ 4816.865384] 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 [ 4816.876646] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4816.877160] Lustre: Skipped 5 previous similar messages [ 4816.878214] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4820.437615] Lustre: server umount lustre-MDT0000 complete [ 4823.853226] LustreError: 124361:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787794907 with bad export cookie 5981814237265875887 [ 4823.862310] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4823.869958] LustreError: 124361:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 4824.264778] Lustre: server umount lustre-MDT0001 complete [ 4837.975442] Lustre: server umount lustre-OST0000 complete [ 4851.202546] Lustre: server umount lustre-OST0001 complete [ 4869.973395] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 4883.080868] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4889.211696] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4898.884056] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4904.338153] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4907.148790] Lustre: 160558:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4914.758058] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4922.147496] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4924.341075] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 4928.435690] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4931.909318] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4937.199043] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 4937.219565] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4939.626510] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4948.782872] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4952.721406] Lustre: 162428:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4962.623283] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 21:44:04 (1787795044) [ 4964.349405] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4966.393497] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 21:44:08 (1787795048) [ 4968.270684] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4970.636770] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 21:44:12 (1787795052) [ 4972.554217] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4974.672839] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 21:44:16 (1787795056) [ 4985.958905] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 21:44:28 (1787795068) [ 5001.393482] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 21:44:43 (1787795083) [ 5017.166940] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 21:44:59 (1787795099) [ 5033.545808] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 21:45:15 (1787795115) [ 5057.334994] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 21:45:39 (1787795139) [ 5091.683740] Lustre: *** cfs_fail_loc=1632, val=0*** [ 5108.913621] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 21:46:30 (1787795190) [ 5111.836937] Lustre: Failing over lustre-MDT0001 [ 5112.237915] Lustre: server umount lustre-MDT0001 complete [ 5114.337643] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 5114.348726] 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 [ 5114.366592] Lustre: Skipped 2 previous similar messages [ 5120.835126] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5121.432988] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5121.445641] Lustre: lustre-MDT0001: Aborting client recovery [ 5121.451949] LustreError: 166216:0:(ldlm_lib.c:3029:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 5121.456970] Lustre: 166241:0:(ldlm_lib.c:2429:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5121.461907] Lustre: 166241:0:(genops.c:1601:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 6d629067-b63c-4650-a31b-199df2f50ec1@ [ 5121.469435] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 5121.477955] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 5121.500818] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 5121.549830] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 5121.572474] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 5126.629231] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 5126.653283] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5126.661207] Lustre: Skipped 2 previous similar messages [ 5127.817945] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5131.906382] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 5137.318904] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 5137.709298] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 5146.259656] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 21:47:08 (1787795228) [ 5154.877448] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5157.951136] Lustre: Failing over lustre-MDT0000 [ 5158.238497] Lustre: server umount lustre-MDT0000 complete [ 5162.467801] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5168.136285] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5168.226807] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5168.472577] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5168.481161] Lustre: Skipped 2 previous similar messages [ 5171.260377] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5173.736293] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5173.752874] Lustre: Skipped 1 previous similar message [ 5173.787420] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 5173.841978] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5173.846112] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 5174.430646] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5184.489928] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 21:47:46 (1787795266) [ 5211.983667] Lustre: Failing over lustre-OST0000 [ 5212.124776] Lustre: server umount lustre-OST0000 complete [ 5212.268134] LustreError: 163135:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5212.290233] LustreError: 163135:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 36 previous similar messages [ 5218.740945] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5229.904887] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5230.019775] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5230.022237] Lustre: Skipped 6 previous similar messages [ 5231.433984] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5231.727092] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5237.488780] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5248.365030] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5248.613628] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5254.205944] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5254.514860] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5261.213676] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff99f188139000.ost_server_uuid 50 [ 5262.819367] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff99f188139000.ost_server_uuid in FULL state after 0 sec [ 5311.974610] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5311.980554] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5311.982523] LustreError: Skipped 1 previous similar message [ 5311.994844] Lustre: Skipped 6 previous similar messages [ 5317.090186] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5317.093267] Lustre: Skipped 3 previous similar messages [ 5318.278739] Lustre: server umount lustre-MDT0000 complete [ 5327.290582] LustreError: 159398:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787795410 with bad export cookie 5981814237265958697 [ 5327.291730] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5327.300285] LustreError: 159398:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 5327.330644] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5327.335470] Lustre: Skipped 1 previous similar message [ 5327.806936] Lustre: server umount lustre-MDT0001 complete [ 5338.155315] Lustre: server umount lustre-OST0000 complete [ 5347.006554] Lustre: server umount lustre-OST0001 complete [ 5364.143258] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing unload_modules_local [ 5367.272878] Key type lgssc unregistered [ 5367.651391] LNet: 175355:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5367.664500] LNetError: 175355:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5367.704348] LNet: Removed LNI 192.168.202.114@tcp [ 5368.726273] Key type .llcrypt unregistered [ 5368.732968] Key type ._llcrypt unregistered [ 5395.256539] Key type ._llcrypt registered [ 5395.258868] Key type .llcrypt registered [ 5395.364845] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_hostid [ 5413.516425] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 5415.110804] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5415.194127] alg: No test for adler32 (adler32-zlib) [ 5416.454251] Lustre: Lustre: Build Version: 2.17.57_50_g504224c [ 5416.903930] LNet: Added LNI 192.168.202.114@tcp [8/256/0/180] [ 5418.592170] Key type lgssc registered [ 5419.906234] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5473.306710] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing load_modules_local [ 5486.548786] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 5486.585436] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5487.857194] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5487.884767] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5487.986812] Lustre: lustre-MDT0000: new disk, initializing [ 5488.063609] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5488.087692] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5492.562430] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5505.178454] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5505.319573] Lustre: 179809:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 5505.352036] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5505.356432] Lustre: Skipped 1 previous similar message [ 5505.392231] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 5505.461838] Lustre: lustre-MDT0001: new disk, initializing [ 5505.541693] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5505.584315] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5505.610066] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5509.944480] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5514.475483] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5523.176989] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5523.452677] Lustre: lustre-OST0000: new disk, initializing [ 5523.455296] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5523.460325] Lustre: 181747:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5523.523588] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5524.055214] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5524.067924] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5524.183753] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5530.478732] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5544.845911] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5544.973608] Lustre: lustre-OST0001: new disk, initializing [ 5544.976423] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5544.981815] Lustre: 182772:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5545.046353] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5551.738169] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5551.750537] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5551.812254] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5551.875713] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5565.491645] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5573.084948] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5580.037296] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 21:54:21 (1787795661) === [ 5582.059670] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5330 sec ========= 21:54:23 (1787795663) [ 5583.788701] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 21:54:25 (1787795665) === [ 5587.136919] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 21:54:28 (1787795668) === [ 5592.547801] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5592.551236] 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 [ 5592.557080] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5593.058356] 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 [ 5593.065023] Lustre: Skipped 1 previous similar message [ 5598.059623] Lustre: server umount lustre-MDT0000 complete [ 5603.299151] LustreError: 179815:0:(ldlm_lib.c:1190: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. [ 5603.310247] LustreError: 179815:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 8 previous similar messages [ 5606.583785] LustreError: 179802:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787795689 with bad export cookie 439548534673280957 [ 5606.602875] LustreError: MGC192.168.202.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5607.405809] Lustre: server umount lustre-MDT0001 complete [ 5624.608243] Lustre: 176969:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787795691/real 1787795691] req@ffff8c24451df840 x1874639454293248/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787795707 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5624.656209] 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 [ 5624.671175] Lustre: Skipped 1 previous similar message [ 5627.680130] Lustre: 176971:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787795694/real 1787795694] req@ffff8c25572b8b40 x1874639454293504/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787795710 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5628.770694] Lustre: 176969:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787795696/real 1787795696] req@ffff8c25572b83c0 x1874639454293760/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787795712 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5628.897945] Lustre: server umount lustre-OST0000 complete [ 5631.968448] Lustre: 176972:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787795699/real 1787795699] req@ffff8c244afcb840 x1874639454294144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787795715 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5637.095284] Lustre: 176972:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787795704/real 1787795704] req@ffff8c25572ba1c0 x1874639454294400/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787795720 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5640.416830] Lustre: server umount lustre-OST0001 complete [ 5658.438329] Lustre: DEBUG MARKER: oleg214-server.virtnet: executing unload_modules_local [ 5661.171211] Key type lgssc unregistered [ 5661.542490] LNet: 186251:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5661.556315] LNetError: 186251:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5661.573735] LNet: Removed LNI 192.168.202.114@tcp [ 5662.461202] Key type .llcrypt unregistered [ 5662.463062] Key type ._llcrypt unregistered