[ 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 478488289 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.002345] x2apic enabled [ 0.003006] Switched APIC routing to physical x2apic. [ 0.004013] kvm-guest: setup PV IPIs [ 0.007241] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008020] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009009] pid_max: default: 32768 minimum: 301 [ 0.010098] LSM: Security Framework initializing [ 0.011032] Yama: becoming mindful. [ 0.012020] SELinux: Initializing. [ 0.013042] *** VALIDATE selinux *** [ 0.020119] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024032] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026038] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027088] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028095] *** VALIDATE tmpfs *** [ 0.029385] *** VALIDATE proc *** [ 0.030200] *** VALIDATE cgroup *** [ 0.031007] *** VALIDATE cgroup2 *** [ 0.033242] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034156] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036022] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037022] Spectre V2 : User space: Vulnerable [ 0.038008] Speculative Store Bypass: Vulnerable [ 0.041308] debug: unmapping init [mem 0xffffffffb1459000-0xffffffffb1460fff] [ 0.043163] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044494] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045022] ... version: 2 [ 0.046013] ... bit width: 48 [ 0.047013] ... generic registers: 4 [ 0.048014] ... value mask: 0000ffffffffffff [ 0.049011] ... max period: 00007fffffffffff [ 0.050009] ... fixed-purpose events: 3 [ 0.050954] ... event mask: 000000070000000f [ 0.052237] rcu: Hierarchical SRCU implementation. [ 0.054412] smp: Bringing up secondary CPUs ... [ 0.055603] x86: Booting SMP configuration: [ 0.056023] .... node #0, CPUs: #1 #2 #3 [ 0.060019] smp: Brought up 1 node, 4 CPUs [ 0.062020] smpboot: Max logical packages: 1 [ 0.063011] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.214145] node 0 deferred pages initialised in 148ms [ 0.217699] devtmpfs: initialized [ 0.219244] x86/mm: Memory block size: 128MB [ 0.221843] gcov: version magic: 0x41383552 [ 0.225252] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.226090] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.227258] pinctrl core: initialized pinctrl subsystem [ 0.228187] [ 0.228699] ************************************************************* [ 0.229013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.230011] ** ** [ 0.231010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.232009] ** ** [ 0.233009] ** This means that this kernel is built to expose internal ** [ 0.234009] ** IOMMU data structures, which may compromise security on ** [ 0.235014] ** your system. ** [ 0.236010] ** ** [ 0.237012] ** If you see this message and you are not debugging the ** [ 0.238022] ** kernel, report this immediately to your vendor! ** [ 0.239012] ** ** [ 0.240014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.241013] ************************************************************* [ 0.242630] NET: Registered protocol family 16 [ 0.243428] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.244062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.245056] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.246428] cpuidle: using governor menu [ 0.248215] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.250398] PCI: Using configuration type 1 for base access [ 0.252127] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.262040] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.263015] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.264204] cryptd: max_cpu_qlen set to 1000 [ 0.266211] ACPI: Added _OSI(Module Device) [ 0.267010] ACPI: Added _OSI(Processor Device) [ 0.268009] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.269008] ACPI: Added _OSI(Processor Aggregator Device) [ 0.272188] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.275555] ACPI: Interpreter enabled [ 0.276071] ACPI: PM: (supports S0 S3 S4 S5) [ 0.277014] ACPI: Using IOAPIC for interrupt routing [ 0.278093] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.279489] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.289820] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.290044] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.291017] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.292077] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.294505] acpiphp: Slot [2] registered [ 0.295214] acpiphp: Slot [5] registered [ 0.296177] acpiphp: Slot [6] registered [ 0.297115] acpiphp: Slot [7] registered [ 0.298194] acpiphp: Slot [8] registered [ 0.299167] acpiphp: Slot [9] registered [ 0.300168] acpiphp: Slot [10] registered [ 0.301266] acpiphp: Slot [3] registered [ 0.302123] acpiphp: Slot [4] registered [ 0.303113] acpiphp: Slot [11] registered [ 0.304169] acpiphp: Slot [12] registered [ 0.305136] acpiphp: Slot [13] registered [ 0.306128] acpiphp: Slot [14] registered [ 0.307105] acpiphp: Slot [15] registered [ 0.308109] acpiphp: Slot [16] registered [ 0.309102] acpiphp: Slot [17] registered [ 0.310116] acpiphp: Slot [18] registered [ 0.311068] acpiphp: Slot [19] registered [ 0.312064] acpiphp: Slot [20] registered [ 0.313079] acpiphp: Slot [21] registered [ 0.314061] acpiphp: Slot [22] registered [ 0.314995] acpiphp: Slot [23] registered [ 0.315058] acpiphp: Slot [24] registered [ 0.316022] acpiphp: Slot [25] registered [ 0.317024] acpiphp: Slot [26] registered [ 0.318074] acpiphp: Slot [27] registered [ 0.319060] acpiphp: Slot [28] registered [ 0.320059] acpiphp: Slot [29] registered [ 0.321062] acpiphp: Slot [30] registered [ 0.322051] acpiphp: Slot [31] registered [ 0.323027] PCI host bridge to bus 0000:00 [ 0.324013] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.325014] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.326019] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.327014] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.328022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.329041] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.330182] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.331952] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.333159] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.339017] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.342069] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.343022] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.344022] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.345019] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.346649] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.347548] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.348032] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.349578] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.351892] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.360020] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.362015] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.365637] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.368020] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.371019] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.378017] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.384451] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.401019] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.410035] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.433026] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.448170] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.467023] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.484027] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.501022] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.512804] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.520014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.525018] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.544026] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.552184] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.557020] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.562018] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.573027] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.581959] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.591021] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.599022] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.623025] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.643071] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.645560] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.648468] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.651458] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.654222] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.660054] iommu: Default domain type: Passthrough [ 0.661421] SCSI subsystem initialized [ 0.663166] ACPI: bus type USB registered [ 0.665094] usbcore: registered new interface driver usbfs [ 0.667107] usbcore: registered new interface driver hub [ 0.669086] usbcore: registered new device driver usb [ 0.671148] pps_core: LinuxPPS API ver. 1 registered [ 0.673013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.676050] PTP clock support registered [ 0.677181] EDAC MC: Ver: 3.0.0 [ 0.679190] PCI: Using ACPI for IRQ routing [ 0.682046] NetLabel: Initializing [ 0.683012] NetLabel: domain hash size = 128 [ 0.685014] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.687121] NetLabel: unlabeled traffic allowed by default [ 0.690147] vgaarb: loaded [ 0.692334] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.694015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.703327] clocksource: Switched to clocksource kvm-clock [ 0.805759] VFS: Disk quotas dquot_6.6.0 [ 0.807328] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.810097] *** VALIDATE ramfs *** [ 0.811415] *** VALIDATE hugetlbfs *** [ 0.813082] pnp: PnP ACPI init [ 0.816354] pnp: PnP ACPI: found 6 devices [ 0.832680] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.836949] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.839262] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.841716] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.844586] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.847176] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.850101] NET: Registered protocol family 2 [ 0.852644] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.858295] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.863272] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.868871] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.872481] TCP: Hash tables configured (established 65536 bind 65536) [ 0.875637] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.878940] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.881950] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.885146] NET: Registered protocol family 1 [ 0.887709] RPC: Registered named UNIX socket transport module. [ 0.890044] RPC: Registered udp transport module. [ 0.891746] RPC: Registered tcp transport module. [ 0.893565] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.896149] NET: Registered protocol family 44 [ 0.897543] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.900345] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.902631] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.905349] PCI: CLS 0 bytes, default 64 [ 0.907511] Unpacking initramfs... [ 2.252549] debug: unmapping init [mem 0xffff89bbfcc54000-0xffff89bbfffbffff] [ 2.256366] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.258269] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.260482] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.757245] Initialise system trusted keyrings [ 2.758393] Key type blacklist registered [ 2.759912] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.768598] zbud: loaded [ 2.771201] *** VALIDATE nfs *** [ 2.772270] *** VALIDATE nfs4 *** [ 2.773395] pstore: using deflate compression [ 2.775821] Platform Keyring initialized [ 2.850234] NET: Registered protocol family 38 [ 2.851649] Key type asymmetric registered [ 2.853080] Asymmetric key parser 'x509' registered [ 2.855387] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.858994] io scheduler mq-deadline registered [ 2.860900] io scheduler kyber registered [ 2.862596] io scheduler bfq registered [ 2.864695] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.868080] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.870893] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.872696] ACPI: Power Button [PWRF] [ 2.877340] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.884682] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.898685] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.906393] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.921784] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.952783] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.982953] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.988441] Non-volatile memory driver v1.3 [ 2.990469] Linux agpgart interface v0.103 [ 3.017948] virtio_blk virtio1: [vda] 150648 512-byte logical blocks (77.1 MB/73.6 MiB) [ 3.020148] vda: detected capacity change from 0 to 77131776 [ 3.034660] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.037527] vdb: detected capacity change from 0 to 1073741824 [ 3.053286] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.056243] vdc: detected capacity change from 0 to 2621440000 [ 3.072910] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.076278] vdd: detected capacity change from 0 to 2621440000 [ 3.091302] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.094219] vde: detected capacity change from 0 to 4294967296 [ 3.108489] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.111597] vdf: detected capacity change from 0 to 4294967296 [ 3.118351] libphy: Fixed MDIO Bus: probed [ 3.131249] usbcore: registered new interface driver usbserial_generic [ 3.133689] usbserial: USB Serial support registered for generic [ 3.135906] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.140117] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.141836] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.143841] mousedev: PS/2 mouse device common for all mice [ 3.146971] rtc_cmos 00:05: RTC can wake from S4 [ 3.149919] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.151262] rtc_cmos 00:05: registered as rtc0 [ 3.159260] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.162700] intel_pstate: CPU model not supported [ 3.165962] hid: raw HID events driver (C) Jiri Kosina [ 3.168690] usbcore: registered new interface driver usbhid [ 3.170500] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.173168] usbhid: USB HID core driver [ 3.173354] drop_monitor: Initializing network drop monitor service [ 3.173491] Initializing XFRM netlink socket [ 3.174961] NET: Registered protocol family 10 [ 3.187060] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.187361] Segment Routing with IPv6 [ 3.191833] NET: Registered protocol family 17 [ 3.193814] mpls_gso: MPLS GSO support [ 3.197681] RAS: Correctable Errors collector initialized. [ 3.199771] AVX version of gcm_enc/dec engaged. [ 3.201563] AES CTR mode by8 optimization enabled [ 3.268160] sched_clock: Marking stable (3268138021, 0)->(4149542761, -881404740) [ 3.271872] registered taskstats version 1 [ 3.273421] Loading compiled-in X.509 certificates [ 3.274851] zswap: loaded using pool lzo/zbud [ 3.298405] Key type big_key registered [ 3.311802] Key type encrypted registered [ 3.313664] ima: No TPM chip found, activating TPM-bypass! [ 3.316207] ima: Allocated hash algorithm: sha1 [ 3.317896] ima: No architecture policies found [ 3.319505] evm: Initialising EVM extended attributes: [ 3.321309] evm: security.selinux [ 3.322599] evm: security.ima [ 3.323668] evm: security.capability [ 3.325044] evm: HMAC attrs: 0x1 [ 3.327521] rtc_cmos 00:05: setting system clock to 2026-09-30 01:55:16 UTC (1790733316) [ 3.332977] debug: unmapping init [mem 0xffffffffb2403000-0xffffffffb25fffff] [ 3.335021] debug: unmapping init [mem 0xffffffffb1182000-0xffffffffb1458fff] [ 3.344140] Write protecting the kernel read-only data: 28672k [ 3.346182] debug: unmapping init [mem 0xffffffffaf803000-0xffffffffaf9fffff] [ 3.348084] debug: unmapping init [mem 0xffffffffb0114000-0xffffffffb01fffff] [ 3.380387] 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.387330] systemd[1]: Detected virtualization kvm. [ 3.389354] systemd[1]: Detected architecture x86-64. [ 3.391551] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.423604] systemd[1]: No hostname configured. [ 3.425460] systemd[1]: Set hostname to . [ 3.427648] random: systemd: uninitialized urandom read (16 bytes read) [ 3.430461] systemd[1]: Initializing machine ID from random generator. [ 3.465433] random: ln: uninitialized urandom read (6 bytes read) [ 3.550137] random: systemd: uninitialized urandom read (16 bytes read) [ 3.552714] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 3.556393] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.559978] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Local File Systems. [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Sockets. Starting Journal Service... Starting Apply Kernel Variables... [ OK ] Started Memstrack Anylazing Service. Starting Create Volatile Files and Directories... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Swap. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.142864] device-mapper: uevent: version 1.0.3 [ 4.145139] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 4.808055] virtio_net virtio0 ens2: renamed from eth0 [ 4.835796] random: fast init done [ 4.864148] scsi host0: ata_piix [ 4.871872] scsi host1: ata_piix [ 4.912039] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 4.913944] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.194623] dracut-initqueue[589]: RTNETLINK answers: File exists [ 9.830347] random: crng init done [ 9.832082] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.102646] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.189246] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.421466] SELinux: Disabled at runtime. [ 11.480554] 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.490128] systemd[1]: Detected virtualization kvm. [ 11.491957] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 11.934299] systemd[1]: initrd-switch-root.service: Succeeded. [ 11.937135] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 11.941460] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 11.945446] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 11.949391] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 11.958970] systemd[1]: Starting Journal Service... Starting Journal Service... [ 11.962895] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit to trigger not loaded. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target rpc_pipefs.target. Mounting Huge Pages File System... Starting Remount Root and Kernel File Systems... Mounting POSIX Message Queue File System... [ OK ] Listening on udev Control Socket. Activating swap /dev/disk/by-label/SWAP... Mounting Kernel Debug File System... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-getty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK [ 12.086810] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... Starting udev Coldplug all Devices... [ OK ] Stopped target Initrd Root File System. [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.402772] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 12.644271] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 12.672751] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 12.775116] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 12.799052] EDAC sbridge: Ver: 1.1.2 [ 14.112660] Key type dns_resolver registered [ 14.406615] NFS: Registering the id_resolver key type [ 14.408543] Key type id_resolver registered [ 14.410117] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... 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 Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started daily update of the root trust anchor for DNSSEC. Starting Login Service... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. 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 oleg101-server login: [ 48.966277] libcfs: loading out-of-tree module taints kernel. [ 49.042195] Key type ._llcrypt registered [ 49.044889] Key type .llcrypt registered [ 49.148692] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_hostid [ 67.064922] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 68.575342] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 68.614643] alg: No test for adler32 (adler32-zlib) [ 70.199517] Lustre: Lustre: Build Version: 2.17.59_3_g4e55f3f [ 71.112791] LNet: Added LNI 192.168.201.101@tcp [8/256/0/180] [ 72.911428] Key type lgssc registered [ 74.829703] Lustre: Echo OBD driver; http://www.lustre.org/ [ 97.820788] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 114.990346] hrtimer: interrupt took 4335482 ns [ 141.768694] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 156.447319] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' or install '{/usr}/sbin/mount.lustre_tgt' [ 156.524027] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 157.761753] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 157.802892] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 157.914335] Lustre: lustre-MDT0000: new disk, initializing [ 158.023801] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 158.044969] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 162.799602] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 176.568083] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 176.656312] Lustre: 6517: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 [ 176.683029] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 176.691066] Lustre: Skipped 1 previous similar message [ 176.772174] Lustre: lustre-MDT0001: new disk, initializing [ 176.826790] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 176.860538] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 176.884680] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 181.299935] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 186.133833] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 195.764036] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 196.087235] Lustre: lustre-OST0000: new disk, initializing [ 196.093819] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 196.102209] Lustre: 8456:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 196.161690] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 202.765630] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 205.879214] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 205.903420] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 206.019544] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 220.111046] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 220.318755] Lustre: lustre-OST0001: new disk, initializing [ 220.322567] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 220.332704] Lustre: 9530:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 220.424985] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 228.696151] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 229.436930] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 229.454324] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 229.573499] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 241.198192] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 248.400796] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 255.407169] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing check_logdir /tmp/testlogs/ [ 261.006736] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing yml_node [ 266.096596] Lustre: DEBUG MARKER: Client: 2.17.59.3 [ 269.561579] Lustre: DEBUG MARKER: MDS: 2.17.59.3 [ 272.122603] Lustre: DEBUG MARKER: OSS: 2.17.59.3 [ 273.999182] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Tue Sep 29 21:59:45 EDT 2026 [ 291.399887] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 303.507203] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 311.777596] 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 [ 311.798711] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 311.802198] Lustre: Skipped 1 previous similar message [ 311.813322] Lustre: Skipped 3 previous similar messages [ 316.897395] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 316.904687] Lustre: Skipped 3 previous similar messages [ 318.148655] Lustre: server umount lustre-MDT0000 complete [ 326.151605] LustreError: 6508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790733639 with bad export cookie 18258010005133165527 [ 326.153446] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 326.166375] LustreError: 6508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 326.624659] Lustre: server umount lustre-MDT0001 complete [ 343.327335] Lustre: 3650:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790733640/real 1790733640] req@ffff89bb4267b100 x1877720048964224/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790733656 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 343.355781] 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 [ 343.379421] Lustre: Skipped 2 previous similar messages [ 345.594109] Lustre: server umount lustre-OST0000 complete [ 347.553646] Lustre: 3652:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790733644/real 1790733644] req@ffff89bb43627100 x1877720048964480/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790733660 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 348.646808] Lustre: 3649:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790733645/real 1790733645] req@ffff89bb42772300 x1877720048964736/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790733661 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 352.748208] Lustre: 3652:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790733649/real 1790733649] req@ffff89bb4267ad80 x1877720048965120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790733665 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 354.554631] Lustre: server umount lustre-OST0001 complete [ 371.638283] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing unload_modules_local [ 374.120706] Key type lgssc unregistered [ 374.406762] LNet: 14814:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 374.411899] LNetError: 14814:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 374.422931] LNet: Removed LNI 192.168.201.101@tcp [ 375.532425] Key type .llcrypt unregistered [ 375.535857] Key type ._llcrypt unregistered [ 400.755652] Key type ._llcrypt registered [ 400.760063] Key type .llcrypt registered [ 400.889219] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_hostid [ 417.282150] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 418.129731] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 418.205911] alg: No test for adler32 (adler32-zlib) [ 419.271650] Lustre: Lustre: Build Version: 2.17.59_3_g4e55f3f [ 419.500411] LNet: Added LNI 192.168.201.101@tcp [8/256/0/180] [ 421.167243] Key type lgssc registered [ 422.126330] Lustre: Echo OBD driver; http://www.lustre.org/ [ 466.149138] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 478.535930] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' or install '{/usr}/sbin/mount.lustre_tgt' [ 478.562411] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 479.803338] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 479.839811] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 479.941938] Lustre: lustre-MDT0000: new disk, initializing [ 480.065835] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 480.091338] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 483.855334] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 497.182501] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 497.256513] Lustre: 19286: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 [ 497.282447] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 497.291100] Lustre: Skipped 1 previous similar message [ 497.375988] Lustre: lustre-MDT0001: new disk, initializing [ 497.440773] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 497.475975] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 497.489598] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 501.753996] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 506.426760] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 516.197046] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 516.466701] Lustre: lustre-OST0000: new disk, initializing [ 516.471961] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 516.480590] Lustre: 21222:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 516.569765] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 522.959444] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 524.348336] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 524.361370] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 524.404580] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 536.959085] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 537.089403] Lustre: lustre-OST0001: new disk, initializing [ 537.092688] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 537.096533] Lustre: 22248:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 537.163252] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 542.797550] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 542.816750] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 542.891598] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 543.461574] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 555.060978] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 566.876590] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 575.082432] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 22:04:46 (1790733886) === [ 578.034975] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 22:04:50 (1790733890) [ 578.612988] Lustre: 19293:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 292, rollback = 2 [ 578.642335] Lustre: 19293:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 578.652825] Lustre: 19293:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 578.664740] Lustre: 19293:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 578.673391] Lustre: 19293:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 578.681659] Lustre: 19293:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 579.195924] Lustre: 19293:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 292, rollback = 2 [ 579.207508] Lustre: 19293:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 8 previous similar messages [ 579.221603] Lustre: 19293:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 579.255664] Lustre: 19293:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 579.268382] Lustre: 19293:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 579.279307] Lustre: 19293:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 579.288685] Lustre: 19293:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 579.299118] Lustre: 19293:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 579.315079] Lustre: 19293:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 579.322119] Lustre: 19293:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 579.333440] Lustre: 19293:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 579.340540] Lustre: 19293:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 580.227483] Lustre: 19293:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 292, rollback = 2 [ 580.233608] Lustre: 19293:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 38 previous similar messages [ 580.238495] Lustre: 19293:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 580.242223] Lustre: 19293:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 38 previous similar messages [ 580.285683] Lustre: 19291:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 580.291524] Lustre: 19291:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 580.296874] Lustre: 19291:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 580.305185] Lustre: 19291:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 580.346334] Lustre: 19291:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 580.350933] Lustre: 19291:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 580.356298] Lustre: 19291:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 580.361308] Lustre: 19291:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 582.262710] Lustre: 19291:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 292, rollback = 2 [ 582.270888] Lustre: 19291:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 125 previous similar messages [ 582.282872] Lustre: 19291:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 582.289551] Lustre: 19291:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 582.295509] Lustre: 19291:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 582.311731] Lustre: 19291:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 122 previous similar messages [ 582.316664] Lustre: 19291:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 582.323438] Lustre: 19291:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 122 previous similar messages [ 582.424358] Lustre: 19291:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 582.427971] Lustre: 19291:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 122 previous similar messages [ 582.432674] Lustre: 19291:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 582.437331] Lustre: 19291:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 122 previous similar messages [ 585.810098] Lustre: *** cfs_fail_loc=1600, val=3*** [ 588.896571] Lustre: 21213:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 588.913501] Lustre: 21212:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 588.920115] Lustre: 21213:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 103 previous similar messages [ 588.920142] Lustre: 21213:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 588.920147] Lustre: 21213:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 102 previous similar messages [ 588.920154] Lustre: 21213:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 588.920158] Lustre: 21213:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 102 previous similar messages [ 588.920163] Lustre: 21213:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 588.920166] Lustre: 21213:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 588.920172] Lustre: 21213:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 588.920175] Lustre: 21213:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 589.020604] Lustre: 21212:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 108 previous similar messages [ 590.342290] Lustre: *** cfs_fail_loc=1600, val=3*** [ 604.647686] 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 [ 604.658896] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 604.669706] Lustre: Skipped 1 previous similar message [ 604.685549] Lustre: Skipped 3 previous similar messages [ 609.772960] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 609.777579] Lustre: Skipped 3 previous similar messages [ 609.998271] Lustre: server umount lustre-MDT0000 complete [ 613.413069] LustreError: 19278:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790733926 with bad export cookie 8355480988557945720 [ 613.417605] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 613.421851] LustreError: 19278:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 613.606439] Lustre: server umount lustre-MDT0001 complete [ 627.656209] Lustre: server umount lustre-OST0000 complete [ 641.528363] Lustre: server umount lustre-OST0001 complete [ 650.011441] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 22:06:02 (1790733962) [ 665.379903] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 674.936957] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 675.503323] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 680.497690] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 680.935164] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 680.967213] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 685.023950] LustreError: 26308:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 689.588312] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 689.909102] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 694.976581] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 698.276505] Lustre: 27449:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 705.834654] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 706.133026] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 715.109638] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 715.366819] LustreError: 27804:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 720.483195] LustreError: 27804:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 720.502957] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:40 to 0x280000401:65) [ 720.503490] LustreError: 27804:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 725.882947] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 731.124646] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 733.519435] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 741.708784] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 745.400312] Lustre: 29319:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 746.691613] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 292, rollback = 2 [ 746.698273] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 68 previous similar messages [ 746.703237] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 746.707675] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 746.711913] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 746.717709] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 69 previous similar messages [ 746.722591] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 746.726845] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 69 previous similar messages [ 746.732598] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 746.736690] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 69 previous similar messages [ 746.740214] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 746.744585] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 69 previous similar messages [ 750.966459] Lustre: *** cfs_fail_loc=1501, val=0*** [ 759.006856] Lustre: Failing over lustre-MDT0000 [ 759.298333] Lustre: server umount lustre-MDT0000 complete [ 761.831883] 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 [ 761.833252] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 761.833617] LustreError: 26303:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 761.848139] Lustre: Skipped 4 previous similar messages [ 770.883666] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 771.006368] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 771.321650] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 771.325713] Lustre: Skipped 1 previous similar message [ 771.410811] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 776.690828] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 776.697600] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 776.732861] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 776.795983] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 776.799047] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 777.243178] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 780.993150] Lustre: *** cfs_fail_loc=1505, val=0*** [ 790.132994] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 22:08:21 (1790734101) [ 792.396986] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 292, rollback = 2 [ 792.403250] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 322 previous similar messages [ 792.407839] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 792.411955] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 792.415455] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 792.422265] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 792.428071] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 792.432790] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 792.437044] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 792.440107] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 792.443630] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 792.446994] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 796.558851] Lustre: *** cfs_fail_loc=1502, val=0*** [ 806.487032] Lustre: Failing over lustre-MDT0000 [ 806.805044] Lustre: server umount lustre-MDT0000 complete [ 807.410481] 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 [ 807.414315] LustreError: 26304:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 807.427568] Lustre: Skipped 3 previous similar messages [ 807.429502] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 807.471908] LustreError: 26304:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 9 previous similar messages [ 817.883314] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 817.946694] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 818.237410] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 823.046855] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 823.268572] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 823.286931] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 823.299798] Lustre: Skipped 3 previous similar messages [ 823.330169] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 823.385578] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 823.397994] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 826.970834] Lustre: *** cfs_fail_loc=1505, val=0*** [ 835.613323] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 22:09:07 (1790734147) [ 837.005366] Lustre: 26302:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 292, rollback = 2 [ 837.011780] Lustre: 26302:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 322 previous similar messages [ 837.017125] Lustre: 26302:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 837.021877] Lustre: 26302:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 837.026717] Lustre: 26302:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 837.031348] Lustre: 26302:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 837.039859] Lustre: 26302:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 837.045115] Lustre: 26302:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 837.049795] Lustre: 26302:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 837.054818] Lustre: 26302:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 837.059923] Lustre: 26302:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 837.064992] Lustre: 26302:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 841.932744] Lustre: *** cfs_fail_loc=1504, val=0*** [ 841.935237] Lustre: *** cfs_fail_loc=1504, val=0*** [ 841.947212] Lustre: Skipped 1 previous similar message [ 851.527664] Lustre: Failing over lustre-MDT0000 [ 852.088598] Lustre: server umount lustre-MDT0000 complete [ 853.983569] 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 [ 853.990287] Lustre: Skipped 1 previous similar message [ 853.994827] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 854.014529] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [ 862.708778] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 862.827652] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 863.087890] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 863.092281] Lustre: Skipped 1 previous similar message [ 863.123784] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 867.469645] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 868.322168] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 868.328594] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 868.352468] Lustre: Skipped 3 previous similar messages [ 868.373906] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 868.428122] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 868.429040] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 871.243686] Lustre: *** cfs_fail_loc=1505, val=0*** [ 878.382426] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 22:09:50 (1790734190) [ 884.038830] Lustre: *** cfs_fail_loc=1603, val=0*** [ 893.128875] Lustre: Failing over lustre-MDT0000 [ 893.605087] Lustre: server umount lustre-MDT0000 complete [ 893.919530] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 893.922083] 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 [ 893.930091] Lustre: Skipped 3 previous similar messages [ 893.938170] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 893.950788] LustreError: 26307:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 6 previous similar messages [ 905.449283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 905.708575] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 906.039303] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 911.329079] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 911.350414] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 911.354350] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 911.363972] Lustre: Skipped 3 previous similar messages [ 911.412298] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 911.476546] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 911.484384] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 921.909625] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 22:10:33 (1790734233) [ 923.794823] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 292, rollback = 2 [ 923.804528] Lustre: 26303:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 644 previous similar messages [ 923.809655] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 923.815464] Lustre: 26303:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 923.820994] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 923.825645] Lustre: 26303:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 923.832455] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 923.839545] Lustre: 26303:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 923.847573] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 923.862708] Lustre: 26303:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 923.870962] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 923.881353] Lustre: 26303:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 929.614840] Lustre: *** cfs_fail_loc=1604, val=0*** [ 938.656124] Lustre: Failing over lustre-MDT0000 [ 939.247860] Lustre: server umount lustre-MDT0000 complete [ 942.052575] 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 [ 942.070324] Lustre: Skipped 5 previous similar messages [ 951.579128] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 951.689779] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 952.057035] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 956.657051] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 957.417144] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 957.425316] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 957.452334] Lustre: Skipped 3 previous similar messages [ 957.468922] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 957.518706] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 957.522169] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 968.313462] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 22:11:19 (1790734279) [ 974.295710] Lustre: *** cfs_fail_loc=1605, val=0*** [ 983.207517] Lustre: Failing over lustre-MDT0000 [ 985.488900] Lustre: server umount lustre-MDT0000 complete [ 988.127958] 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 [ 988.150844] Lustre: Skipped 3 previous similar messages [ 988.156037] LustreError: 27312:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 988.177195] LustreError: 27312:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 19 previous similar messages [ 999.118720] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 999.270300] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 999.566878] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 999.573521] Lustre: Skipped 2 previous similar messages [ 999.621126] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1004.803584] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1005.026866] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1005.027658] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1005.038820] Lustre: Skipped 3 previous similar messages [ 1005.083581] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1005.135100] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1005.135674] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 1015.329791] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 22:12:07 (1790734327) [ 1021.665651] Lustre: *** cfs_fail_loc=161d, val=0*** [ 1028.258246] Lustre: Failing over lustre-MDT0000 [ 1028.682907] Lustre: server umount lustre-MDT0000 complete [ 1030.624867] 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 [ 1030.647060] Lustre: Skipped 1 previous similar message [ 1030.657365] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1042.898124] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1043.075681] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1043.634903] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1049.068604] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1049.069743] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1049.081386] Lustre: Skipped 3 previous similar messages [ 1049.125557] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1049.186985] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1049.188016] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 1050.497653] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1061.801553] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 22:12:53 (1790734373) [ 1063.552491] Lustre: 27312:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 292, rollback = 2 [ 1063.560918] Lustre: 27312:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 967 previous similar messages [ 1063.565940] Lustre: 27312:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1063.571018] Lustre: 27312:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 967 previous similar messages [ 1063.578987] Lustre: 27312:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 1063.584097] Lustre: 27312:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 967 previous similar messages [ 1063.589893] Lustre: 27312:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1063.595421] Lustre: 27312:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 967 previous similar messages [ 1063.601696] Lustre: 27312:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1063.607044] Lustre: 27312:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 967 previous similar messages [ 1063.612993] Lustre: 27312:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1063.618206] Lustre: 27312:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 967 previous similar messages [ 1065.056995] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1075.964543] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 22:13:08 (1790734388) [ 1081.850111] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1083.288287] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1096.465441] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 22:13:28 (1790734408) [ 1132.201039] Lustre: Failing over lustre-MDT0000 [ 1132.529246] Lustre: server umount lustre-MDT0000 complete [ 1136.100452] 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 [ 1136.108869] LustreError: 40314:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1136.111383] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1136.119670] Lustre: Skipped 6 previous similar messages [ 1136.159392] LustreError: 40314:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 22 previous similar messages [ 1138.321669] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1149.348183] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1152.479252] Lustre: 16435:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790734449/real 1790734449] req@ffff89bc70e8b100 x1877720414506112/t0(0) o400->MGC192.168.201.101@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1790734465 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1152.519642] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1161.937586] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1161.953956] Lustre: lustre-MDT0000: reset Object Index mappings [ 1163.769480] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x73f4a1b09a88c392 [ 1163.787050] Lustre: MGC192.168.201.101@tcp: Connection restored to 0@lo (at 0@lo) [ 1163.792426] Lustre: Skipped 3 previous similar messages [ 1164.121502] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1169.379529] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1169.410100] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1169.463631] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1169.468303] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1169.468619] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1174.116314] LustreError: 42962:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1174.130547] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1176.223215] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1176.225436] Lustre: Skipped 1 previous similar message [ 1183.170885] Lustre: Failing over lustre-MDT0000 [ 1183.388897] Lustre: server umount lustre-MDT0000 complete [ 1194.487382] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1200.157081] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1200.159851] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1200.417766] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1204.484759] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1213.086708] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 22:15:25 (1790734525) [ 1215.544593] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1225.943329] Lustre: Failing over lustre-MDT0000 [ 1226.227221] Lustre: server umount lustre-MDT0000 complete [ 1230.816460] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1233.071916] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1245.986990] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1246.175131] Lustre: 16438:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790734543/real 1790734543] req@ffff89bc5fe31f80 x1877720414605568/t0(0) o400->MGC192.168.201.101@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1790734559 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1259.977593] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1259.986992] Lustre: lustre-MDT0000: reset Object Index mappings [ 1271.788258] LustreError: 16434:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff89bc7f688700 x1877720414617984/t0(0) o250->MGC192.168.201.101@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 [ 1272.235736] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1272.243602] Lustre: Skipped 3 previous similar messages [ 1272.294110] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1272.307530] Lustre: Skipped 1 previous similar message [ 1277.410696] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1277.417299] Lustre: Skipped 1 previous similar message [ 1277.421534] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1277.434939] Lustre: Skipped 8 previous similar messages [ 1277.488708] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1277.499901] Lustre: Skipped 1 previous similar message [ 1277.506529] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1277.548241] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1277.550783] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1281.248219] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1281.260586] Lustre: Skipped 2 previous similar messages [ 1293.442144] Lustre: Failing over lustre-MDT0000 [ 1295.834575] Lustre: server umount lustre-MDT0000 complete [ 1297.889191] 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 [ 1297.891511] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1297.904795] Lustre: Skipped 9 previous similar messages [ 1306.102855] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1306.251748] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1306.266812] LustreError: Skipped 2 previous similar messages [ 1311.233945] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1311.815700] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1311.817111] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1314.824839] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1314.829321] Lustre: Skipped 84 previous similar messages [ 1323.453386] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 22:17:15 (1790734635) [ 1324.855117] Lustre: 26304:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 292, rollback = 2 [ 1324.861948] Lustre: 26304:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 954 previous similar messages [ 1324.867738] Lustre: 26304:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 1324.872306] Lustre: 26304:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 955 previous similar messages [ 1324.877368] Lustre: 26304:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 1324.882811] Lustre: 26304:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 955 previous similar messages [ 1324.887347] Lustre: 26304:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1324.891795] Lustre: 26304:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 955 previous similar messages [ 1324.896179] Lustre: 26304:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1324.901866] Lustre: 26304:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 955 previous similar messages [ 1324.906698] Lustre: 26304:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1324.911807] Lustre: 26304:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 955 previous similar messages [ 1330.853984] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1330.865140] Lustre: Skipped 7 previous similar messages [ 1350.302315] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 22:17:42 (1790734662) [ 1358.492924] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1358.494991] Lustre: Skipped 8 previous similar messages [ 1383.983649] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 22:18:15 (1790734695) [ 1394.160132] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1394.167189] Lustre: Skipped 13 previous similar messages [ 1400.410642] Lustre: Failing over lustre-MDT0000 [ 1400.753868] Lustre: server umount lustre-MDT0000 complete [ 1403.873824] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1403.882564] LustreError: 26304:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1403.895625] LustreError: 26304:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 84 previous similar messages [ 1410.970449] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1411.540437] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1411.558994] Lustre: Skipped 1 previous similar message [ 1416.675332] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1416.675917] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1416.686291] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1416.688510] Lustre: Skipped 7 previous similar messages [ 1416.707785] Lustre: Skipped 1 previous similar message [ 1416.715664] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1416.722674] Lustre: Skipped 1 previous similar message [ 1416.768635] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:853 to 0x280000401:897) [ 1416.773900] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:854 to 0x2c0000401:897) [ 1426.627851] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 22:18:58 (1790734738) [ 1443.253335] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 1464.203246] Lustre: 52930:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1491.410940] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1495.740439] Lustre: 54067:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1503.299422] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1503.304858] Lustre: Skipped 81 previous similar messages [ 1506.071898] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1507.103146] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1508.128099] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1510.182915] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1510.184733] Lustre: Skipped 1 previous similar message [ 1510.883363] Lustre: Failing over lustre-MDT0000 [ 1511.433802] Lustre: server umount lustre-MDT0000 complete [ 1513.964854] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1521.619848] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1527.007048] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1527.439627] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 1527.453581] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:946 to 0x280000401:961) [ 1540.166661] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 22:20:51 (1790734851) [ 1547.744820] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1547.758239] Lustre: Skipped 3 previous similar messages [ 1549.612430] Lustre: server umount lustre-MDT0000 complete [ 1553.793881] LustreError: 26288:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790734866 with bad export cookie 8355480988558159178 [ 1553.814637] LustreError: 26288:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1554.268722] Lustre: server umount lustre-MDT0001 complete [ 1568.635510] Lustre: server umount lustre-OST0000 complete [ 1582.973403] Lustre: server umount lustre-OST0001 complete [ 1590.419827] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_hostid [ 1598.709805] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 1650.395341] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 1660.450283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1660.849795] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1660.907488] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1661.053755] Lustre: lustre-MDT0000: new disk, initializing [ 1661.179593] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1666.600119] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1677.627716] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1677.783355] Lustre: 59129: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 [ 1677.844705] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1677.849349] Lustre: Skipped 1 previous similar message [ 1677.986399] Lustre: lustre-MDT0001: new disk, initializing [ 1678.131357] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1678.147405] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1683.415685] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1687.714727] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1696.424119] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1697.011745] Lustre: lustre-OST0000: new disk, initializing [ 1697.026095] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1697.031555] Lustre: 60762:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1698.571800] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1698.608817] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1698.847505] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1707.063878] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1720.467427] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1720.678994] Lustre: lustre-OST0001: new disk, initializing [ 1720.684186] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1720.694916] Lustre: 61633:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1722.697832] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1722.726364] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1722.806115] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1728.981630] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1738.982856] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1743.084934] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1754.204571] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1755.274384] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1755.276327] Lustre: Skipped 19 previous similar messages [ 1760.730110] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1760.733017] Lustre: Skipped 6 previous similar messages [ 1777.602817] Lustre: Failing over lustre-MDT0000 [ 1778.058409] Lustre: server umount lustre-MDT0000 complete [ 1779.168314] 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 [ 1779.200889] Lustre: Skipped 15 previous similar messages [ 1787.885409] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1788.025976] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1788.043849] LustreError: Skipped 3 previous similar messages [ 1788.261210] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1788.265234] Lustre: Skipped 7 previous similar messages [ 1788.292834] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1788.298211] Lustre: Skipped 1 previous similar message [ 1793.454430] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1793.515653] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1793.525592] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1793.528390] Lustre: Skipped 1 previous similar message [ 1793.543336] Lustre: Skipped 7 previous similar messages [ 1793.571568] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1793.586677] Lustre: Skipped 1 previous similar message [ 1793.631600] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1793.643939] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1793.650251] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1804.234939] Lustre: Failing over lustre-MDT0000 [ 1806.657788] Lustre: server umount lustre-MDT0000 complete [ 1808.875967] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1808.889341] LustreError: Skipped 1 previous similar message [ 1817.908916] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1822.323394] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1823.777612] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1823.782188] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1823.782684] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1828.361773] Lustre: Failing over lustre-MDT0000 [ 1830.624211] Lustre: server umount lustre-MDT0000 complete [ 1838.865859] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1843.560883] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1844.237148] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1844.249541] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1849.457367] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1862.645418] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 22:26:15 (1790735175) [ 1879.053957] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 1900.564158] Lustre: 68587:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1924.516811] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1928.419885] Lustre: 69724:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1936.820080] Lustre: 59137:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 292, rollback = 2 [ 1936.829146] Lustre: 59137:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 2759 previous similar messages [ 1936.838262] Lustre: 59137:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1936.846420] Lustre: 59137:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 1936.855640] Lustre: 59137:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 1936.868581] Lustre: 59137:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 1936.880447] Lustre: 59137:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1936.892993] Lustre: 59137:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 1936.914696] Lustre: 59137:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1936.930968] Lustre: 59137:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 1936.943283] Lustre: 59137:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1936.949446] Lustre: 59137:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2040.602768] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 22:29:12 (1790735352) [ 2091.308533] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2091.311648] Lustre: Skipped 4 previous similar messages [ 2115.165073] Lustre: *** cfs_fail_loc=160c, val=0*** [ 2115.174662] Lustre: Skipped 8 previous similar messages [ 2152.017276] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 22:31:04 (1790735464) [ 2193.343704] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2194.356149] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2194.358036] Lustre: Skipped 69 previous similar messages [ 2196.357814] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2196.360702] Lustre: Skipped 116 previous similar messages [ 2200.363783] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2200.365762] Lustre: Skipped 234 previous similar messages [ 2208.370579] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2208.372445] Lustre: Skipped 455 previous similar messages [ 2224.422454] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2224.427465] Lustre: Skipped 838 previous similar messages [ 2256.449580] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2256.454162] Lustre: Skipped 1539 previous similar messages [ 2262.037697] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2262.042531] Lustre: Skipped 2599 previous similar messages [ 2502.484483] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 22:36:54 (1790735814) [ 2582.835446] Lustre: 59136:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 320, rollback = 2 [ 2582.844461] Lustre: 59136:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 36831 previous similar messages [ 2582.851278] Lustre: 59136:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 1/4/0 [ 2582.856292] Lustre: 59136:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2582.863214] Lustre: 59136:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 5/5/0, xattr_set: 7/320/0 [ 2582.868728] Lustre: 59136:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2582.874566] Lustre: 59136:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 6/46/0, punch: 0/0/0, quota 1/3/0 [ 2582.885034] Lustre: 59136:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2582.894080] Lustre: 59136:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 2/5/0 [ 2582.899487] Lustre: 59136:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2582.905349] Lustre: 59136:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/1 [ 2582.911963] Lustre: 59136:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2654.346540] Lustre: server umount lustre-MDT0000 complete [ 2658.272063] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2658.285053] LustreError: Skipped 1 previous similar message [ 2658.286687] 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 [ 2658.314837] Lustre: Skipped 13 previous similar messages [ 2658.321089] LustreError: 60835:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2658.347279] LustreError: 60835:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 43 previous similar messages [ 2658.869840] LustreError: 68589:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790735972 with bad export cookie 8355480988558178274 [ 2658.870419] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2658.879349] LustreError: 68589:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2658.914140] LustreError: Skipped 2 previous similar messages [ 2659.223833] Lustre: server umount lustre-MDT0001 complete [ 2673.727365] Lustre: server umount lustre-OST0000 complete [ 2687.357144] Lustre: server umount lustre-OST0001 complete [ 2696.519798] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2707.718577] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2723.359499] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2728.480903] LustreError: 75353:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.101@tcp: failed processing log, type 4: rc = -110 [ 2754.272584] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2754.284451] Lustre: Skipped 2 previous similar messages [ 2761.580657] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2765.020715] Lustre: 75937: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. [ 2765.050175] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2768.103886] Lustre: 75937:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2779.140203] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 22:41:30 (1790736090) [ 2796.852452] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 2807.252267] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2807.497327] LustreError: 75378:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2807.619326] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2811.933642] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2821.752609] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2826.945668] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2829.716592] Lustre: 78604:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2844.839358] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2850.282934] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2851.313310] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2860.164610] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2864.657798] Lustre: 80101:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2870.407435] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2878.450220] Lustre: Failing over lustre-OST0000 [ 2878.586296] Lustre: server umount lustre-OST0000 complete [ 2888.768297] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2889.042665] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2889.052543] Lustre: Skipped 2 previous similar messages [ 2890.088658] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2890.093894] Lustre: Skipped 2 previous similar messages [ 2890.116555] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2890.120229] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2890.127081] Lustre: *** cfs_fail_loc=215, val=0*** [ 2890.131097] Lustre: Skipped 2 previous similar messages [ 2890.145986] Lustre: Skipped 11 previous similar messages [ 2895.330051] Lustre: *** cfs_fail_loc=215, val=0*** [ 2895.343335] Lustre: Skipped 2 previous similar messages [ 2897.101739] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2900.447572] Lustre: *** cfs_fail_loc=215, val=0*** [ 2900.756565] Lustre: 81499: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. [ 2900.807791] Lustre: 81499:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2904.125192] Lustre: Failing over lustre-OST0000 [ 2904.424629] Lustre: server umount lustre-OST0000 complete [ 2915.282637] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2917.404323] Lustre: *** cfs_fail_loc=215, val=0*** [ 2917.416746] Lustre: Skipped 2 previous similar messages [ 2922.384623] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2922.464418] Lustre: *** cfs_fail_loc=215, val=0*** [ 2922.470515] Lustre: Skipped 1 previous similar message [ 2931.171083] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2931.176512] Lustre: Skipped 3 previous similar messages [ 2936.289347] LustreError: 77453:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2936.306168] LustreError: 77453:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 34 previous similar messages [ 2938.258524] Lustre: server umount lustre-MDT0000 complete [ 2941.497675] LustreError: 75360:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790736254 with bad export cookie 8355480988559736313 [ 2941.525276] LustreError: 75360:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2941.794430] Lustre: server umount lustre-MDT0001 complete [ 2955.947319] Lustre: server umount lustre-OST0000 complete [ 2970.012416] Lustre: server umount lustre-OST0001 complete [ 2978.530184] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 22:44:50 (1790736290) [ 2994.449648] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 3004.502637] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3009.174602] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3017.512804] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3022.033976] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3025.026781] Lustre: 85887:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3032.916392] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3040.778848] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3048.950464] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 3049.843506] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3055.092826] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 3056.526683] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3064.432751] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3067.910531] Lustre: 87757:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3099.581708] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 22:46:51 (1790736411) [ 3116.500187] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 22:47:08 (1790736428) [ 3118.035691] Lustre: *** cfs_fail_loc=160f, val=0*** [ 3130.984094] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 22:47:22 (1790736442) [ 3135.885144] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3135.889410] Lustre: Skipped 7 previous similar messages [ 3188.192262] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3188.205461] Lustre: Skipped 3 previous similar messages [ 3193.315233] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3194.388718] Lustre: server umount lustre-MDT0000 complete [ 3198.441892] LustreError: 88533:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3198.460246] LustreError: 88533:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 14 previous similar messages [ 3200.027921] LustreError: 84725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790736513 with bad export cookie 8355480988559744769 [ 3200.048544] LustreError: 84725:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3200.856979] Lustre: server umount lustre-MDT0001 complete [ 3216.234112] Lustre: server umount lustre-OST0000 complete [ 3219.753555] Lustre: 16437:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790736516/real 1790736516] req@ffff89bc7cd79f80 x1877720419056512/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790736532 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3221.579505] Lustre: server umount lustre-OST0001 complete [ 3240.880203] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 3251.953090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3257.599344] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3266.140401] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3271.503963] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3274.622865] Lustre: 93624:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3281.992979] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3289.433996] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3291.563909] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3297.766995] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 3299.217323] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3304.433454] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 3304.591753] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 3305.655668] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3313.703498] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3318.192919] Lustre: 95507:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3326.151788] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 22:50:37 (1790736637) [ 3329.365846] Lustre: 92481:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 292, rollback = 2 [ 3329.372451] Lustre: 92481:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 1360 previous similar messages [ 3329.381344] Lustre: 92481:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 3329.387244] Lustre: 92481:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1360 previous similar messages [ 3329.396100] Lustre: 92481:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3329.410333] Lustre: 92481:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 1360 previous similar messages [ 3329.419791] Lustre: 92481:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3329.425601] Lustre: 92481:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1360 previous similar messages [ 3329.438635] Lustre: 92481:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3329.452113] Lustre: 92481:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1360 previous similar messages [ 3329.460214] Lustre: 92481:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3329.464655] Lustre: 92481:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 1360 previous similar messages [ 3333.950612] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3333.954942] Lustre: Skipped 63 previous similar messages [ 3360.736029] 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 [ 3360.738355] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3360.747721] Lustre: Skipped 15 previous similar messages [ 3360.776019] Lustre: Skipped 6 previous similar messages [ 3365.858418] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3373.023145] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3373.521318] Lustre: server umount lustre-MDT0000 complete [ 3377.805932] LustreError: 92466:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790736690 with bad export cookie 8355480988559773175 [ 3377.811575] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3377.822151] LustreError: 92466:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3377.861037] LustreError: Skipped 2 previous similar messages [ 3378.289522] Lustre: server umount lustre-MDT0001 complete [ 3392.956796] Lustre: server umount lustre-OST0000 complete [ 3407.220543] Lustre: server umount lustre-OST0001 complete [ 3427.650448] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 3438.739133] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3439.221523] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3439.229193] Lustre: Skipped 13 previous similar messages [ 3443.770885] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3452.378082] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3457.189236] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3460.713564] Lustre: 99548:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3467.865523] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3476.142235] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3477.502316] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3485.694371] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3486.148838] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3491.840779] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3491.844379] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3494.130558] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3503.214123] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3518.291282] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 22:53:50 (1790736830) [ 3521.535257] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3521.538483] Lustre: Skipped 63 previous similar messages [ 3521.848838] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3534.220805] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 22:54:06 (1790736846) [ 3536.199346] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3536.280708] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3536.291428] Lustre: Skipped 2 previous similar messages [ 3546.393995] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 22:54:18 (1790736858) [ 3547.758871] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3549.651885] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 22:54:21 (1790736861) [ 3555.342624] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3555.344813] LustreError: 98415:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3555.370932] LustreError: 98415:0:(mdt_reint.c:2656:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s15 failed: rc = -5 [ 3616.743478] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3616.755049] LustreError: Skipped 1 previous similar message [ 3616.775867] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3616.790490] Lustre: Skipped 7 previous similar messages [ 3625.132943] Lustre: server umount lustre-MDT0000 complete [ 3634.626933] LustreError: 98387:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790736947 with bad export cookie 8355480988559787917 [ 3634.983550] Lustre: server umount lustre-MDT0001 complete [ 3651.423131] Lustre: 16436:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790736948/real 1790736948] req@ffff89bc45079c00 x1877720419752576/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790736964 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3653.838461] Lustre: server umount lustre-OST0000 complete [ 3655.135240] Lustre: 16438:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790736952/real 1790736952] req@ffff89bb4547c000 x1877720419752832/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790736968 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3661.344096] Lustre: 16438:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790736958/real 1790736958] req@ffff89bc4507a300 x1877720419753472/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790736974 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3661.384729] Lustre: 16438:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3662.640830] Lustre: server umount lustre-OST0001 complete [ 3679.505751] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing unload_modules_local [ 3682.320552] Key type lgssc unregistered [ 3682.633735] LNet: 105252:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3682.651644] LNetError: 105252:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3682.664838] LNet: Removed LNI 192.168.201.101@tcp [ 3683.676164] Key type .llcrypt unregistered [ 3683.680248] Key type ._llcrypt unregistered [ 3707.961364] Key type ._llcrypt registered [ 3707.963427] Key type .llcrypt registered [ 3708.053391] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_hostid [ 3723.674456] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 3725.084821] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3725.117727] alg: No test for adler32 (adler32-zlib) [ 3726.387474] Lustre: Lustre: Build Version: 2.17.59_3_g4e55f3f [ 3726.822970] LNet: Added LNI 192.168.201.101@tcp [8/256/0/180] [ 3728.671273] Key type lgssc registered [ 3729.939889] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3788.197972] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 3800.926478] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' or install '{/usr}/sbin/mount.lustre_tgt' [ 3800.960671] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3802.227306] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3802.264991] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3802.326377] Lustre: lustre-MDT0000: new disk, initializing [ 3802.383449] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3802.397396] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3806.873560] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3818.648364] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3818.773596] Lustre: 109724: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 [ 3818.799449] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3818.803262] Lustre: Skipped 1 previous similar message [ 3818.866612] Lustre: lustre-MDT0001: new disk, initializing [ 3818.935411] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3818.979566] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3818.996544] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3822.914354] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3828.050584] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3836.760463] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3836.972956] Lustre: lustre-OST0000: new disk, initializing [ 3836.976663] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3836.983354] Lustre: 111661:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3837.039204] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3842.842838] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3843.076534] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3843.085287] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3843.119400] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3856.910928] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3857.199413] Lustre: lustre-OST0001: new disk, initializing [ 3857.213141] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3857.229145] Lustre: 112683:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3857.373377] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3864.621565] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3864.635422] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3864.641972] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3864.706519] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3876.685516] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3887.896962] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3893.968941] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 23:00:05 (1790737205) === [ 3902.363865] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 23:00:14 (1790737214) [ 3902.940943] Lustre: 113408:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 292, rollback = 2 [ 3902.956420] Lustre: 113408:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3902.964726] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3902.971656] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3902.977396] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3902.989561] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3903.548789] Lustre: 111649:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 3903.570586] Lustre: 111649:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 5 previous similar messages [ 3903.582161] Lustre: 111649:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3903.591396] Lustre: 111649:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3903.613396] Lustre: 111649:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 3903.624102] Lustre: 111649:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3903.632913] Lustre: 111649:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 3903.640082] Lustre: 111649:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3903.645677] Lustre: 111649:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3903.660045] Lustre: 111649:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3903.666699] Lustre: 111649:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3903.670691] Lustre: 111649:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 3904.553217] Lustre: 109732:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 292, rollback = 2 [ 3904.559902] Lustre: 109732:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 81 previous similar messages [ 3904.591726] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3904.597748] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 84 previous similar messages [ 3904.625244] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3904.637173] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 3904.647576] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3904.660068] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 3904.674032] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3904.685476] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 3904.697390] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3904.711911] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 3907.119101] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3918.843843] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 23:00:31 (1790737231) [ 3920.304558] Lustre: 113408:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 292, rollback = 2 [ 3920.314311] Lustre: 113408:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 221 previous similar messages [ 3920.330630] Lustre: 113408:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 3920.345251] Lustre: 113408:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 218 previous similar messages [ 3920.358297] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3920.364728] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 215 previous similar messages [ 3920.377120] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3920.397974] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 215 previous similar messages [ 3920.406368] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3920.414917] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 215 previous similar messages [ 3920.422827] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3920.439219] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 215 previous similar messages [ 3921.683089] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3922.260060] Lustre: *** cfs_fail_loc=1614, val=103*** [ 3922.266057] Lustre: Skipped 1 previous similar message [ 3927.070546] Lustre: 111651:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3927.082986] Lustre: 111651:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3927.095176] Lustre: 111651:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3927.105536] Lustre: 111651:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3927.111096] Lustre: 111651:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3927.122560] Lustre: 111651:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3927.129908] Lustre: 111651:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3927.136981] Lustre: 111651:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3927.141493] Lustre: 111651:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3927.148795] Lustre: 111651:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3927.157968] Lustre: 111651:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3927.170582] Lustre: 111651:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3936.566657] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 23:00:48 (1790737248) [ 3937.367757] Lustre: 113408:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 292, rollback = 2 [ 3937.374460] Lustre: 113408:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 1 previous similar message [ 3937.380553] Lustre: 113408:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3937.387484] Lustre: 113408:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3937.393384] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3937.399629] Lustre: 113408:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3937.404695] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3937.409257] Lustre: 113408:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3937.414344] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3937.419546] Lustre: 113408:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3937.426821] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3937.432633] Lustre: 113408:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 1 previous similar message [ 3940.355880] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3940.363616] Lustre: Skipped 1 previous similar message [ 3941.990711] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3941.999572] Lustre: Skipped 1 previous similar message [ 3961.912514] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3963.924115] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 23:01:15 (1790737275) [ 3964.573348] Lustre: 109731:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 292, rollback = 2 [ 3964.579987] Lustre: 109731:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3964.585311] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3964.591972] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3964.597079] Lustre: 109731:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 3964.605023] Lustre: 109731:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3964.614906] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3964.620921] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3964.628691] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3964.635885] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3964.641949] Lustre: 109731:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3964.647796] Lustre: 109731:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3967.160693] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3967.219276] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3969.353384] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3969.355099] Lustre: Skipped 3 previous similar messages [ 3988.717752] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 23:01:40 (1790737300) [ 3990.991333] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3990.997610] Lustre: Skipped 5 previous similar messages [ 4028.387844] 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 [ 4028.401750] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4028.402208] Lustre: Skipped 1 previous similar message [ 4028.416267] Lustre: Skipped 3 previous similar messages [ 4031.204737] Lustre: server umount lustre-MDT0000 complete [ 4035.079499] LustreError: 109716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790737348 with bad export cookie 1284313428725029149 [ 4035.081879] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4035.085831] LustreError: 109716:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4035.545098] Lustre: server umount lustre-MDT0001 complete [ 4049.503110] Lustre: server umount lustre-OST0000 complete [ 4062.863246] Lustre: server umount lustre-OST0001 complete [ 4077.945327] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 4087.041427] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4087.316867] LustreError: 118411:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4087.350165] LustreError: 118411:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 4087.411293] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4091.320256] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4092.903602] LustreError: 118412:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4096.998426] LustreError: 118411:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4099.953764] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4100.369394] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4105.038958] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4107.988628] Lustre: 119551:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4114.787410] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4121.290925] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4125.216472] LustreError: 119903:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4125.245942] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 4130.283048] LustreError: 119903:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4130.345978] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4130.479036] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4130.482950] Lustre: Skipped 1 previous similar message [ 4132.538267] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 4132.541636] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 4132.548624] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 4137.426179] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4144.731840] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4148.674787] Lustre: 121420:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4163.556824] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 23:04:35 (1790737475) [ 4164.057448] Lustre: 118406:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 292, rollback = 2 [ 4164.064268] Lustre: 118406:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 46 previous similar messages [ 4164.069598] Lustre: 118406:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4164.075020] Lustre: 118406:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4164.079779] Lustre: 118406:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 4164.084491] Lustre: 118406:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4164.090416] Lustre: 118406:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 4164.095198] Lustre: 118406:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4164.102400] Lustre: 118406:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 4164.105222] Lustre: 118406:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4164.113671] Lustre: 118406:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4164.118303] Lustre: 118406:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4165.888288] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4165.890955] Lustre: Skipped 3 previous similar messages [ 4202.978172] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4202.988087] 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 [ 4203.016490] Lustre: Skipped 2 previous similar messages [ 4203.024908] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4204.514828] 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 [ 4204.517362] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4204.530063] Lustre: Skipped 1 previous similar message [ 4204.538709] Lustre: Skipped 1 previous similar message [ 4205.936313] Lustre: server umount lustre-MDT0000 complete [ 4209.364813] LustreError: 118391:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790737522 with bad export cookie 1284313428725044402 [ 4209.380448] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4209.653449] Lustre: server umount lustre-MDT0001 complete [ 4222.204440] Lustre: server umount lustre-OST0000 complete [ 4224.992382] Lustre: 106873:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790737522/real 1790737522] req@ffff89bb44c1ce00 x1877723881697920/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790737538 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4225.031733] 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 [ 4225.045720] Lustre: Skipped 1 previous similar message [ 4226.028841] Lustre: server umount lustre-OST0001 complete [ 4242.587362] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 4251.716876] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4252.097603] LustreError: 123987:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4252.149196] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4256.521312] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4265.240856] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4269.659627] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4272.950419] Lustre: 125126:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4280.084807] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4286.029468] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4290.548322] LustreError: 125479:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4290.568268] LustreError: 125479:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 4290.581075] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 4294.222634] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4297.454090] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 4297.454319] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 4297.572787] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 4301.102620] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4308.956135] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4312.623322] Lustre: 126996:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4318.350049] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4318.407055] Lustre: 127249:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 4318.418537] Lustre: 127249:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4318.434422] Lustre: 127249:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4318.443698] Lustre: 127249:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4318.449599] Lustre: 127249:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 4318.453636] Lustre: 127249:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4318.459139] Lustre: 127249:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 4318.467428] Lustre: 127249:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4318.477806] Lustre: 127249:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 4318.484537] Lustre: 127249:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4318.490589] Lustre: 127249:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4318.500790] Lustre: 127249:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4319.349392] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4319.355334] Lustre: Skipped 2 previous similar messages [ 4343.101468] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 23:07:35 (1790737655) [ 4345.820104] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4345.821611] Lustre: Skipped 3 previous similar messages [ 4352.472701] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4374.650867] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 23:08:05 (1790737685) [ 4377.690465] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4393.362580] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 23:08:25 (1790737705) [ 4397.650257] Lustre: *** cfs_fail_loc=162f, val=0*** [ 4397.654823] Lustre: Skipped 9 previous similar messages [ 4413.035588] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 23:08:44 (1790737724) [ 4424.345530] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 23:08:56 (1790737736) [ 4427.092457] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4427.116226] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4427.121124] Lustre: Skipped 3 previous similar messages [ 4431.969859] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.1@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 4433.053723] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.1@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 4441.047888] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 23:09:13 (1790737753) [ 4448.940703] Lustre: 131509:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 263, rollback = 2 [ 4448.950350] Lustre: 131509:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 125 previous similar messages [ 4448.957851] Lustre: 131509:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4448.971317] Lustre: 131509:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 4448.979854] Lustre: 131509:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 2/263/0 [ 4448.989454] Lustre: 131509:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 4449.000464] Lustre: 131509:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/2 [ 4449.011295] Lustre: 131509:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 4449.018911] Lustre: 131509:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 4449.029509] Lustre: 131509:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 4449.036364] Lustre: 131509:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4449.044045] Lustre: 131509:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 4464.550191] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 23:09:36 (1790737776) [ 4471.699505] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 23:09:43 (1790737783) [ 4483.203279] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 23:09:55 (1790737795) [ 4485.674044] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4485.703782] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4485.716975] Lustre: Skipped 1 previous similar message [ 4498.671839] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 23:10:09 (1790737809) [ 4500.328397] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4500.334776] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4512.628294] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 23:10:24 (1790737824) [ 4514.694847] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4530.759972] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4532.591896] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 23:10:44 (1790737844) [ 4538.768580] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4538.776214] Lustre: Skipped 1 previous similar message [ 4541.890109] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4563.109868] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 23:11:14 (1790737874) [ 4565.359136] Lustre: Failing over lustre-MDT0000 [ 4565.623986] Lustre: server umount lustre-MDT0000 complete [ 4566.131549] LustreError: 127410:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.1@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4567.523485] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4567.530345] 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 [ 4575.710662] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4575.905433] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4576.194413] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4576.197584] Lustre: Skipped 3 previous similar messages [ 4576.241507] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4576.861334] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4580.443077] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4581.355170] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4581.400735] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 4581.442686] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4581.459272] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4582.731903] LustreError: 127410:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4595.675960] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 23:11:47 (1790737907) [ 4597.520417] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4597.792573] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4597.798248] Lustre: Skipped 1 previous similar message [ 4609.214134] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 23:12:01 (1790737921) [ 4611.204673] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4621.748730] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 23:12:13 (1790737933) [ 4623.612405] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4635.244690] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 23:12:27 (1790737947) [ 4646.909164] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 23:12:39 (1790737959) [ 4648.361085] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4648.363479] Lustre: Skipped 1 previous similar message [ 4659.336349] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 23:12:51 (1790737971) [ 4674.378961] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 23:13:06 (1790737986) [ 4681.334618] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4681.338557] Lustre: Skipped 1 previous similar message [ 4696.451174] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 23:13:28 (1790738008) [ 4698.250242] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4698.255510] Lustre: Skipped 4 previous similar messages [ 4714.118629] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 23:13:44 (1790738024) [ 4714.480733] Lustre: 127410:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 320, rollback = 2 [ 4714.491853] Lustre: 127410:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 508 previous similar messages [ 4714.502232] Lustre: 127410:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 1/4/0 [ 4714.521735] Lustre: 127410:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 508 previous similar messages [ 4714.532811] Lustre: 127410:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 5/5/1, xattr_set: 7/320/0 [ 4714.551334] Lustre: 127410:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 508 previous similar messages [ 4714.566088] Lustre: 127410:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 6/46/0, punch: 0/0/0, quota 1/3/0 [ 4714.585074] Lustre: 127410:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 508 previous similar messages [ 4714.606924] Lustre: 127410:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 2/33/0, delete: 2/5/1 [ 4714.622272] Lustre: 127410:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 508 previous similar messages [ 4714.635112] Lustre: 127410:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/1 [ 4714.642297] Lustre: 127410:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 508 previous similar messages [ 4746.391963] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 23:14:18 (1790738058) [ 4748.871834] LustreError: 123984:0:(osd_handler.c:286:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4755.726398] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 23:14:27 (1790738067) [ 4779.510545] Lustre: Failing over lustre-MDT0000 [ 4779.682122] Lustre: server umount lustre-MDT0000 complete [ 4781.027561] 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 [ 4781.051348] Lustre: Skipped 5 previous similar messages [ 4781.055211] LustreError: 127249:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4781.060045] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4781.070704] LustreError: 127249:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [ 4791.174950] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4791.384522] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4791.633762] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4791.667848] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4795.808571] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4796.897454] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4796.914797] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4796.928026] Lustre: Skipped 3 previous similar messages [ 4796.961568] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4796.992221] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 4796.996188] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 4809.063436] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 23:15:21 (1790738121) [ 4822.538680] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 23:15:34 (1790738134) [ 4835.028601] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 23:15:47 (1790738147) [ 4836.552631] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4836.555105] Lustre: Skipped 7 previous similar messages [ 4849.520698] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 23:16:01 (1790738161) [ 4855.504992] Lustre: Failing over lustre-MDT0000 [ 4855.924442] Lustre: server umount lustre-MDT0000 complete [ 4858.335576] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4858.339191] 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 [ 4858.373707] Lustre: Skipped 4 previous similar messages [ 4863.668439] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4863.734126] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4863.928979] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4867.911487] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4869.099474] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4869.106148] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4869.120160] Lustre: Skipped 3 previous similar messages [ 4869.173122] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4869.229093] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 4869.231146] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 4880.222918] Lustre: Failing over lustre-MDT0000 [ 4880.500620] Lustre: server umount lustre-MDT0000 complete [ 4889.443969] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4889.568515] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4889.576430] LustreError: 106872:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff89bc50669f80 x1877723882678784/t0(0) o250->MGC192.168.201.101@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 [ 4889.750241] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4891.232305] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4894.375797] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4895.202290] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4895.213051] Lustre: Skipped 3 previous similar messages [ 4895.240799] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4895.273729] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:257) [ 4895.274665] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 4902.835953] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 23:16:54 (1790738214) [ 4918.123410] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 23:17:09 (1790738229) [ 4930.825374] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 23:17:23 (1790738243) [ 4968.534513] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 23:18:00 (1790738280) [ 4969.528141] Lustre: *** cfs_fail_loc=162c, val=0*** [ 4969.533369] Lustre: Skipped 13 previous similar messages [ 4980.527812] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 23:18:12 (1790738292) [ 4988.278190] LustreError: 148404:0:(lfsck_layout.c:4534:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4990.533285] Lustre: Failing over lustre-OST0000 [ 4990.637458] Lustre: server umount lustre-OST0000 complete [ 4991.335744] LustreError: 148404:0:(lfsck_layout.c:4534:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4991.345411] LustreError: 148404:0:(lfsck_layout.c:4534:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4991.969643] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4991.980595] 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 [ 4991.994498] Lustre: Skipped 4 previous similar messages [ 4992.001725] LustreError: 125480:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4992.013920] LustreError: 125480:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 28 previous similar messages [ 4993.248076] LustreError: 148404:0:(lfsck_layout.c:4534:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 5003.648855] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5003.820049] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5005.360661] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5005.391484] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 5005.391549] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5005.413304] Lustre: Skipped 3 previous similar messages [ 5009.654230] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5017.846210] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 23:18:49 (1790738329) [ 5035.412461] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 5053.115301] Lustre: 151207:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5075.092564] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5078.354501] Lustre: 152341:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5088.220959] LustreError: 152455:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5090.725707] Lustre: Failing over lustre-MDT0001 [ 5090.785977] 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 [ 5090.788107] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5090.802926] Lustre: Skipped 2 previous similar messages [ 5090.814774] Lustre: Skipped 4 previous similar messages [ 5091.271140] LustreError: 152455:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5091.303812] LustreError: 152454:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5091.310798] LustreError: 152454:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5091.550293] Lustre: server umount lustre-MDT0001 complete [ 5094.081095] LustreError: 152454:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 5105.470663] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5105.759022] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5105.762029] Lustre: Skipped 3 previous similar messages [ 5105.801453] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5109.932297] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5110.757785] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5110.767772] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5110.774901] Lustre: Skipped 1 previous similar message [ 5110.802667] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5110.892321] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 5110.904838] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 5118.055416] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 23:20:30 (1790738430) [ 5131.629333] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 5151.161368] Lustre: 155174:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5171.103524] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5174.390756] Lustre: 156308:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5191.502757] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 23:21:43 (1790738503) [ 5192.929221] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 5194.476799] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 23:21:46 (1790738506) [ 5199.582482] Lustre: *** cfs_fail_loc=1631, val=0*** [ 5210.084431] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 5210.092537] LustreError: Skipped 1 previous similar message [ 5210.098585] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5211.198178] Lustre: server umount lustre-MDT0000 complete [ 5214.312656] LustreError: 129995:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790738527 with bad export cookie 1284313428725117202 [ 5214.318229] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5214.323117] LustreError: 129995:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 5214.539372] Lustre: server umount lustre-MDT0001 complete [ 5228.632519] Lustre: server umount lustre-OST0000 complete [ 5242.309606] Lustre: server umount lustre-OST0001 complete [ 5256.559638] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 5266.345405] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5266.866205] LustreError: 159063:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5266.899704] LustreError: 159063:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 16 previous similar messages [ 5272.309697] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5282.192914] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5288.810594] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5291.740667] Lustre: 160204:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5298.602526] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5305.276180] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5306.995512] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 5312.106489] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 5313.300223] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5318.636476] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 5318.639387] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 5318.847461] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5325.904888] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5329.148150] Lustre: 162073:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5338.175734] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 23:24:10 (1790738650) [ 5339.932862] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 5341.739790] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 23:24:13 (1790738653) [ 5343.790548] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 5345.722627] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 23:24:17 (1790738657) [ 5347.314693] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 5349.246312] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 23:24:21 (1790738661) [ 5350.610204] Lustre: 159059:0:(osd_internal.h:1462:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 292, rollback = 2 [ 5350.614132] Lustre: 159059:0:(osd_internal.h:1462:osd_trans_exec_op()) Skipped 1922 previous similar messages [ 5350.620633] Lustre: 159059:0:(osd_handler.c:2097:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 5350.624854] Lustre: 159059:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1922 previous similar messages [ 5350.629023] Lustre: 159059:0:(osd_handler.c:2104:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 5/292/0 [ 5350.631838] Lustre: 159059:0:(osd_handler.c:2104:osd_trans_dump_creds()) Skipped 1922 previous similar messages [ 5350.637252] Lustre: 159059:0:(osd_handler.c:2114:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 5350.641568] Lustre: 159059:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1922 previous similar messages [ 5350.645505] Lustre: 159059:0:(osd_handler.c:2121:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 5350.649874] Lustre: 159059:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1922 previous similar messages [ 5350.654845] Lustre: 159059:0:(osd_handler.c:2128:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 5350.660386] Lustre: 159059:0:(osd_handler.c:2128:osd_trans_dump_creds()) Skipped 1922 previous similar messages [ 5359.382192] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 23:24:31 (1790738671) [ 5372.447588] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 23:24:44 (1790738684) [ 5387.584791] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 23:24:59 (1790738699) [ 5405.892893] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 23:25:17 (1790738717) [ 5428.722967] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 23:25:40 (1790738740) [ 5463.751284] Lustre: *** cfs_fail_loc=1632, val=0*** [ 5482.663556] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 23:26:34 (1790738794) [ 5485.700549] Lustre: Failing over lustre-MDT0001 [ 5486.050911] Lustre: server umount lustre-MDT0001 complete [ 5487.585417] 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 [ 5487.588459] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 5487.612568] Lustre: Skipped 6 previous similar messages [ 5493.457612] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5493.910663] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5493.913707] Lustre: lustre-MDT0001: Aborting client recovery [ 5493.931277] LustreError: 165917:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 5493.936551] Lustre: 165941:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5493.941330] Lustre: 165941:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 7e4a8a17-96fc-46b5-bb9b-78869ab43c76@ [ 5493.949616] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 5493.955364] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 5493.966296] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 5494.011814] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:131 to 0x2c0000400:161) [ 5494.014210] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:161) [ 5498.389554] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5498.860749] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 5498.870737] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5498.880611] Lustre: Skipped 2 previous similar messages [ 5506.909939] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 5507.115441] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 5514.594442] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 23:27:06 (1790738826) [ 5526.115109] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5529.470423] Lustre: Failing over lustre-MDT0000 [ 5529.502864] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 5529.514501] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5529.997180] Lustre: server umount lustre-MDT0000 complete [ 5541.473797] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5541.663835] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5542.023945] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5542.032491] Lustre: Skipped 2 previous similar messages [ 5545.582341] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5546.981278] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5546.988631] Lustre: Skipped 1 previous similar message [ 5547.011859] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 5547.044680] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 5547.051185] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5548.630860] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5561.345890] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 23:27:52 (1790738872) [ 5610.413736] Lustre: Failing over lustre-OST0001 [ 5610.479604] Lustre: server umount lustre-OST0001 complete [ 5611.491717] LustreError: lustre-OST0001-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 5618.636634] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null) [ 5632.016893] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5632.216830] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5632.222615] Lustre: Skipped 6 previous similar messages [ 5632.230277] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 5632.611234] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5633.982578] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5633.985811] Lustre: lustre-OST0001-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5634.015549] Lustre: Skipped 3 previous similar messages [ 5638.711579] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5646.812892] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5647.145102] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5651.212585] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5651.373147] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5657.554826] Lustre: DEBUG MARKER: oleg101-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff88d32125f000.ost_server_uuid 50 [ 5658.968436] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff88d32125f000.ost_server_uuid in FULL state after 0 sec [ 5741.539678] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5741.550509] LustreError: Skipped 1 previous similar message [ 5741.553926] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5741.557051] Lustre: Skipped 3 previous similar messages [ 5745.132718] 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 [ 5745.154798] Lustre: Skipped 9 previous similar messages [ 5747.887297] Lustre: server umount lustre-MDT0000 complete [ 5757.982797] LustreError: 159045:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790739071 with bad export cookie 1284313428725200089 [ 5757.985586] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5758.004790] LustreError: 159045:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5758.387936] Lustre: server umount lustre-MDT0001 complete [ 5775.839686] Lustre: 106875:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739073/real 1790739073] req@ffff89bc4740e680 x1877723883477888/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739089 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5777.082827] Lustre: server umount lustre-OST0000 complete [ 5778.721407] Lustre: 106873:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739075/real 1790739075] req@ffff89bc7c4b5c00 x1877723883478144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739091 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5781.026413] Lustre: 106875:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739078/real 1790739078] req@ffff89bc4740df80 x1877723883478400/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739094 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5784.548988] Lustre: 106874:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739081/real 1790739081] req@ffff89bc76cbd880 x1877723883478784/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739097 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5786.545566] Lustre: server umount lustre-OST0001 complete [ 5806.485617] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing unload_modules_local [ 5810.430975] Key type lgssc unregistered [ 5810.634975] LNet: 175615:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5810.640272] LNetError: 175615:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5810.652941] LNet: Removed LNI 192.168.201.101@tcp [ 5812.188358] Key type .llcrypt unregistered [ 5812.190625] Key type ._llcrypt unregistered [ 5836.463390] Key type ._llcrypt registered [ 5836.465553] Key type .llcrypt registered [ 5836.547593] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_hostid [ 5853.363398] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 5854.383304] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5854.492560] alg: No test for adler32 (adler32-zlib) [ 5855.552447] Lustre: Lustre: Build Version: 2.17.59_3_g4e55f3f [ 5855.799383] LNet: Added LNI 192.168.201.101@tcp [8/256/0/180] [ 5857.479903] Key type lgssc registered [ 5858.647657] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5908.548156] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing load_modules_local [ 5921.827442] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' or install '{/usr}/sbin/mount.lustre_tgt' [ 5921.843751] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5923.054667] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5923.082599] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5923.150311] Lustre: lustre-MDT0000: new disk, initializing [ 5923.253805] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5923.290327] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5929.091320] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5943.158331] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5943.333314] Lustre: 180085: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 [ 5943.355828] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5943.359603] Lustre: Skipped 1 previous similar message [ 5943.441859] Lustre: lustre-MDT0001: new disk, initializing [ 5943.545036] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5943.583789] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5943.608235] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5947.673887] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5953.181375] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5963.569738] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5963.782233] Lustre: lustre-OST0000: new disk, initializing [ 5963.784880] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5963.794166] Lustre: 182022:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5963.868409] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5968.916673] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5968.919746] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5969.038557] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5969.614481] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5982.158368] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5982.285863] Lustre: lustre-OST0001: new disk, initializing [ 5982.289572] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5982.301627] Lustre: 183045:0:(osd_compat.c:1354:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5982.406474] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5987.873306] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5987.879309] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5987.927164] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5988.531984] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5999.939446] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6010.620588] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6016.802148] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 23:35:29 (1790739329) === [ 6018.639833] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5743 sec ========= 23:35:30 (1790739330) [ 6020.503833] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 23:35:32 (1790739332) === [ 6024.552978] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 23:35:36 (1790739336) === [ 6028.769415] 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 [ 6028.773677] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6028.795126] Lustre: Skipped 1 previous similar message [ 6028.815114] Lustre: Skipped 3 previous similar messages [ 6033.889640] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6033.899539] Lustre: Skipped 3 previous similar messages [ 6035.175464] Lustre: server umount lustre-MDT0000 complete [ 6044.150106] LustreError: 180093:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6044.188969] LustreError: 180093:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [ 6045.010135] LustreError: 183872:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1790739358 with bad export cookie 710258772757404270 [ 6045.013209] LustreError: MGC192.168.201.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6045.019388] LustreError: 183872:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 6045.298221] Lustre: server umount lustre-MDT0001 complete [ 6065.631593] Lustre: 177236:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739362/real 1790739362] req@ffff89bc6057c380 x1877726113907456/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739378 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6065.685673] 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 [ 6065.699401] Lustre: Skipped 2 previous similar messages [ 6066.655571] Lustre: 177238:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739363/real 1790739363] req@ffff89bc7e229880 x1877726113907712/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739379 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6066.831736] Lustre: server umount lustre-OST0000 complete [ 6070.824830] Lustre: 177236:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790739367/real 1790739367] req@ffff89bc7e338380 x1877726113907968/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1790739383 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6074.975289] Lustre: server umount lustre-OST0001 complete [ 6092.554512] Lustre: DEBUG MARKER: oleg101-server.virtnet: executing unload_modules_local [ 6096.505050] Key type lgssc unregistered [ 6096.974572] LNet: 186519:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6096.978709] LNetError: 186519:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6096.997675] LNet: Removed LNI 192.168.201.101@tcp [ 6098.209157] Key type .llcrypt unregistered [ 6098.210989] Key type ._llcrypt unregistered